Package: cloud-init Version: 20.2-2 Severity: normal I started a cloud-image supplying the attached user-data, meta-data (empty) and network-config through a NoCloud ISO image. After booting the image, cloud-init created the expected configuration in /etc/udev/rules/70-persistent-net.rules and /etc/network/interfaces.d/50-cloud-init. However, the network interface doesn't actually get renamed and configured. Instead a configuration with dhcp enabled is created in /run/network/interfaces.d/ and is used to configure the interface. When the machine is booted a second time, the udev rule renames the interface as appropriate and the interface is configured with the supplied static network configuration. This seems to happen, because udev doesn't evaluate the udev rule after it is created, because rules for that interface were already processed earlier after boot. cloud-init apparently doesn't trigger renaming the interface explicitly after creating the udev rule, unless the `set-name` property is set for that interface. This problem can be worked aroung, by setting the `set-name` property, which causes cloud-init to rename the interface itself. However I would expect that cloud-init handles the missing `set-name` either by recognizing that the eni renderer always requires the interface to be renamed and act as if `set-name` was given or that it at least fails with a coherent failure message, stating that `set-name` needs to be set when the eni renderer is used. The current behavior that ends up in a silent semi-failure state is really confusing. I used the following official cloud image: debian-11-genericcloud-amd64-daily-20200716-329.qcow2 The cloud-init logs are attached Regards Sven -- System Information: Debian Release: bullseye/sid APT prefers testing APT policy: (500, 'testing') Architecture: amd64 (x86_64) Kernel: Linux 5.7.0-1-cloud-amd64 (SMP w/2 CPU threads) Locale: LANG=C.UTF-8, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE not set Shell: /bin/sh linked to /usr/bin/dash Init: systemd (via /run/systemd/system) LSM: AppArmor: enabled Versions of packages cloud-init depends on: ii fdisk 2.35.2-6 ii gdisk 1.0.5-1 ii ifupdown 0.8.35+b1 ii locales 2.30-8 ii lsb-base 11.1.0 ii lsb-release 11.1.0 ii net-tools 1.60+git20180626.aebd88e-1 ii procps 2:3.3.16-5 ii python3 3.8.2-3 ii python3-configobj 5.0.6-4 ii python3-jinja2 2.11.2-1 ii python3-jsonpatch 1.25-3 ii python3-jsonschema 3.2.0-3 ii python3-oauthlib 3.1.0-2 ii python3-requests 2.23.0+dfsg-2 ii python3-yaml 5.3.1-2 ii util-linux 2.35.2-6 Versions of packages cloud-init recommends: ii cloud-guest-utils 0.31-2 pn eatmydata <none> ii sudo 1.9.1-1 Versions of packages cloud-init suggests: pn btrfs-progs <none> ii e2fsprogs 1.45.6-1 pn xfsprogs <none> -- no debconf information
2020-07-16 13:02:42,838 - util.py[DEBUG]: Cloud-init v. 20.2 running 'init-local' at Thu, 16 Jul 2020 13:02:42 +0000. Up 1.99 seconds.
2020-07-16 13:02:42,838 - main.py[DEBUG]: No kernel command line url found.
2020-07-16 13:02:42,838 - main.py[DEBUG]: Closing stdin.
2020-07-16 13:02:42,840 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-07-16 13:02:42,841 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:4
2020-07-16 13:02:42,841 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
2020-07-16 13:02:42,841 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net
2020-07-16 13:02:42,841 - handlers.py[DEBUG]: start: init-local/check-cache: attempting to read from cache [check]
2020-07-16 13:02:42,841 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-07-16 13:02:42,841 - stages.py[DEBUG]: no cache found
2020-07-16 13:02:42,841 - handlers.py[DEBUG]: finish: init-local/check-cache: SUCCESS: no cache found
2020-07-16 13:02:42,841 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-07-16 13:02:42,843 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.debian.Distro'>
2020-07-16 13:02:42,843 - __init__.py[DEBUG]: Looking for data source in: ['NoCloud', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2020-07-16 13:02:42,845 - __init__.py[DEBUG]: Searching for local data source in: ['DataSourceNoCloud']
2020-07-16 13:02:42,846 - handlers.py[DEBUG]: start: init-local/search-NoCloud: searching for local data from DataSourceNoCloud
2020-07-16 13:02:42,846 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceNoCloud.DataSourceNoCloud'>
2020-07-16 13:02:42,846 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: New instance first boot
2020-07-16 13:02:42,846 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:42,851 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:42,852 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Read 145 bytes from /proc/1/environ
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Read 1037 bytes from /proc/self/status
2020-07-16 13:02:42,853 - util.py[DEBUG]: querying dmi data /sys/class/dmi/id/product_serial
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /sys/class/dmi/id/product_serial (quiet=False)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Read 1 bytes from /sys/class/dmi/id/product_serial
2020-07-16 13:02:42,853 - util.py[DEBUG]: dmi data /sys/class/dmi/id/product_serial returned
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/user-data (quiet=False)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/meta-data (quiet=False)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/vendor-data (quiet=False)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/network-config (quiet=False)
2020-07-16 13:02:42,853 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/user-data (quiet=False)
2020-07-16 13:02:42,854 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/meta-data (quiet=False)
2020-07-16 13:02:42,854 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/vendor-data (quiet=False)
2020-07-16 13:02:42,854 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/network-config (quiet=False)
2020-07-16 13:02:42,865 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-07-16 13:02:42,865 - util.py[DEBUG]: Read 200 bytes from /etc/os-release
2020-07-16 13:02:42,866 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-07-16 13:02:42,877 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-07-16 13:02:42,882 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=CIDATA', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-07-16 13:02:42,887 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-07-16 13:02:42,892 - DataSourceNoCloud.py[DEBUG]: Attempting to use data from /dev/sr0
2020-07-16 13:02:42,892 - util.py[DEBUG]: Reading from /proc/mounts (quiet=False)
2020-07-16 13:02:42,892 - util.py[DEBUG]: Read 2395 bytes from /proc/mounts
2020-07-16 13:02:42,892 - util.py[DEBUG]: Fetched {'sysfs': {'fstype': 'sysfs', 'mountpoint': '/sys', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'proc': {'fstype': 'proc', 'mountpoint': '/proc', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'udev': {'fstype': 'devtmpfs', 'mountpoint': '/dev', 'opts': 'rw,nosuid,noexec,relatime,size=494016k,nr_inodes=123504,mode=755'}, 'devpts': {'fstype': 'devpts', 'mountpoint': '/dev/pts', 'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000'}, 'tmpfs': {'fstype': 'tmpfs', 'mountpoint': '/sys/fs/cgroup', 'opts': 'ro,nosuid,nodev,noexec,mode=755'}, '/dev/sda1': {'fstype': 'ext4', 'mountpoint': '/', 'opts': 'rw,relatime,discard,errors=remount-ro'}, 'securityfs': {'fstype': 'securityfs', 'mountpoint': '/sys/kernel/security', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'cgroup2': {'fstype': 'cgroup2', 'mountpoint': '/sys/fs/cgroup/unified', 'opts': 'rw,nosuid,nodev,noexec,relatime,nsdelegate'}, 'cgroup': {'fstype': 'cgroup', 'mountpoint': '/sys/fs/cgroup/perf_event', 'opts': 'rw,nosuid,nodev,noexec,relatime,perf_event'}, 'pstore': {'fstype': 'pstore', 'mountpoint': '/sys/fs/pstore', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'efivarfs': {'fstype': 'efivarfs', 'mountpoint': '/sys/firmware/efi/efivars', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'none': {'fstype': 'bpf', 'mountpoint': '/sys/fs/bpf', 'opts': 'rw,nosuid,nodev,noexec,relatime,mode=700'}, 'systemd-1': {'fstype': 'autofs', 'mountpoint': '/proc/sys/fs/binfmt_misc', 'opts': 'rw,relatime,fd=29,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=10339'}, 'hugetlbfs': {'fstype': 'hugetlbfs', 'mountpoint': '/dev/hugepages', 'opts': 'rw,relatime,pagesize=2M'}, 'mqueue': {'fstype': 'mqueue', 'mountpoint': '/dev/mqueue', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'debugfs': {'fstype': 'debugfs', 'mountpoint': '/sys/kernel/debug', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'tracefs': {'fstype': 'tracefs', 'mountpoint': '/sys/kernel/tracing', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, '/dev/sda15': {'fstype': 'vfat', 'mountpoint': '/boot/efi', 'opts': 'rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro'}} mounts from proc
2020-07-16 13:02:42,892 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'auto', '/dev/sr0', '/run/cloud-init/tmp/tmpj6go0b74'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:42,903 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpj6go0b74//user-data (quiet=False)
2020-07-16 13:02:42,903 - util.py[DEBUG]: Read 656 bytes from /run/cloud-init/tmp/tmpj6go0b74//user-data
2020-07-16 13:02:42,903 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpj6go0b74//meta-data (quiet=False)
2020-07-16 13:02:42,903 - util.py[DEBUG]: Read 0 bytes from /run/cloud-init/tmp/tmpj6go0b74//meta-data
2020-07-16 13:02:42,903 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpj6go0b74//vendor-data (quiet=False)
2020-07-16 13:02:42,903 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpj6go0b74//network-config (quiet=False)
2020-07-16 13:02:42,903 - util.py[DEBUG]: Read 144 bytes from /run/cloud-init/tmp/tmpj6go0b74//network-config
2020-07-16 13:02:42,903 - util.py[DEBUG]: Running command ['umount', '/run/cloud-init/tmp/tmpj6go0b74'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:42,907 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,908 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-16 13:02:42,908 - util.py[DEBUG]: Attempting to load yaml from string of length 144 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,909 - DataSourceNoCloud.py[DEBUG]: Using data from /dev/sr0
2020-07-16 13:02:42,909 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-07-16 13:02:42,909 - util.py[DEBUG]: Read 109 bytes from /etc/hosts
2020-07-16 13:02:42,910 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmp12cukssj) - w: [600] 4435 bytes/chars
2020-07-16 13:02:42,910 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data.json (via temporary file /run/cloud-init/tmp8edog07t) - w: [644] 1343 bytes/chars
2020-07-16 13:02:42,911 - handlers.py[DEBUG]: finish: init-local/search-NoCloud: SUCCESS: found local data from DataSourceNoCloud
2020-07-16 13:02:42,911 - stages.py[INFO]: Loaded datasource DataSourceNoCloud - DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-07-16 13:02:42,911 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-07-16 13:02:42,911 - util.py[DEBUG]: Read 2637 bytes from /etc/cloud/cloud.cfg
2020-07-16 13:02:42,911 - util.py[DEBUG]: Attempting to load yaml from string of length 2637 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,917 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-07-16 13:02:42,917 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-07-16 13:02:42,917 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,919 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00_debian.cfg (quiet=False)
2020-07-16 13:02:42,919 - util.py[DEBUG]: Read 93 bytes from /etc/cloud/cloud.cfg.d/00_debian.cfg
2020-07-16 13:02:42,919 - util.py[DEBUG]: Attempting to load yaml from string of length 93 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,920 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-16 13:02:42,920 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-07-16 13:02:42,920 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,920 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,920 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-16 13:02:42,920 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-07-16 13:02:42,921 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/nocloud'
2020-07-16 13:02:42,921 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/nocloud/datasource (quiet=False)
2020-07-16 13:02:42,921 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/datasource - wb: [644] 65 bytes
2020-07-16 13:02:42,922 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 65 bytes
2020-07-16 13:02:42,922 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-07-16 13:02:42,922 - stages.py[DEBUG]: previous iid found to be NO_PREVIOUS_INSTANCE_ID
2020-07-16 13:02:42,922 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 8 bytes
2020-07-16 13:02:42,922 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 8 bytes
2020-07-16 13:02:42,922 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 24 bytes
2020-07-16 13:02:42,923 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 4721 bytes
2020-07-16 13:02:42,923 - main.py[DEBUG]: [local] init will now be targeting instance id: nocloud. new=True
2020-07-16 13:02:42,923 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-07-16 13:02:42,923 - util.py[DEBUG]: Read 2637 bytes from /etc/cloud/cloud.cfg
2020-07-16 13:02:42,923 - util.py[DEBUG]: Attempting to load yaml from string of length 2637 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,929 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-07-16 13:02:42,929 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-07-16 13:02:42,929 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,931 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00_debian.cfg (quiet=False)
2020-07-16 13:02:42,931 - util.py[DEBUG]: Read 93 bytes from /etc/cloud/cloud.cfg.d/00_debian.cfg
2020-07-16 13:02:42,931 - util.py[DEBUG]: Attempting to load yaml from string of length 93 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,932 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-16 13:02:42,932 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-07-16 13:02:42,932 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,932 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:42,932 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-16 13:02:42,933 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.debian.Distro'>
2020-07-16 13:02:42,933 - util.py[DEBUG]: Reading from /sys/class/net/enp1s0/address (quiet=False)
2020-07-16 13:02:42,933 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/enp1s0/address
2020-07-16 13:02:42,933 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-07-16 13:02:42,933 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/enp1s0/addr_assign_type (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/enp1s0/addr_assign_type
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/enp1s0/uevent (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 27 bytes from /sys/class/net/enp1s0/uevent
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/enp1s0/address (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/enp1s0/address
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/enp1s0/device/device (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/enp1s0/device/device
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/enp1s0/type (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/enp1s0/type
2020-07-16 13:02:42,934 - util.py[DEBUG]: Reading from /sys/class/net/lo/type (quiet=False)
2020-07-16 13:02:42,934 - util.py[DEBUG]: Read 4 bytes from /sys/class/net/lo/type
2020-07-16 13:02:42,934 - __init__.py[DEBUG]: net: all expected physical devices present
2020-07-16 13:02:42,934 - stages.py[DEBUG]: applying net config names for {'version': 2, 'ethernets': {'main': {'match': {'macaddress': '52:54:00:8c:fc:10'}, 'addresses': ['192.168.122.100'], 'gateway4': '192.168.122.1'}}}
2020-07-16 13:02:42,934 - __init__.py[DEBUG]: no interfaces to rename
2020-07-16 13:02:42,935 - stages.py[INFO]: Applying network configuration from ds bringup=False: {'version': 2, 'ethernets': {'main': {'match': {'macaddress': '52:54:00:8c:fc:10'}, 'addresses': ['192.168.122.100'], 'gateway4': '192.168.122.1'}}}
2020-07-16 13:02:42,935 - __init__.py[DEBUG]: Selected renderer 'eni' from priority list: None
2020-07-16 13:02:42,935 - network_state.py[DEBUG]: v2(ethernets) -> v1(physical):
{'type': 'physical', 'name': 'main', 'mac_address': '52:54:00:8c:fc:10', 'match': {'macaddress': '52:54:00:8c:fc:10'}, 'subnets': [{'type': 'static', 'address': '192.168.122.100', 'gateway': '192.168.122.1'}]}
2020-07-16 13:02:42,936 - network_state.py[DEBUG]: v2_common: handling config:
{'main': {'match': {'macaddress': '52:54:00:8c:fc:10'}, 'addresses': ['192.168.122.100'], 'gateway4': '192.168.122.1'}}
2020-07-16 13:02:42,937 - util.py[DEBUG]: Writing to /etc/network/interfaces.d/50-cloud-init - wb: [644] 434 bytes
2020-07-16 13:02:42,937 - util.py[DEBUG]: Writing to /etc/udev/rules.d/70-persistent-net.rules - wb: [644] 96 bytes
2020-07-16 13:02:42,937 - main.py[DEBUG]: [local] Exiting. datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net] not in local mode.
2020-07-16 13:02:42,937 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp0e5nbbz4) - w: [644] 518 bytes/chars
2020-07-16 13:02:42,937 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-07-16 13:02:42,937 - util.py[DEBUG]: Read 10 bytes from /proc/uptime
2020-07-16 13:02:42,937 - util.py[DEBUG]: cloud-init mode 'init' took 0.124 seconds (0.12)
2020-07-16 13:02:42,938 - handlers.py[DEBUG]: finish: init-local: SUCCESS: searching for local datasources
2020-07-16 13:02:52,549 - util.py[DEBUG]: Cloud-init v. 20.2 running 'init' at Thu, 16 Jul 2020 13:02:52 +0000. Up 11.70 seconds.
2020-07-16 13:02:52,549 - main.py[DEBUG]: No kernel command line url found.
2020-07-16 13:02:52,549 - main.py[DEBUG]: Closing stdin.
2020-07-16 13:02:52,550 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-07-16 13:02:52,551 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:4
2020-07-16 13:02:52,560 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-07-16 13:02:52,560 - util.py[DEBUG]: Read 200 bytes from /etc/os-release
2020-07-16 13:02:52,560 - util.py[DEBUG]: Running command ['ip', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,564 - util.py[DEBUG]: Running command ['ip', '-o', 'route', 'list'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,566 - util.py[DEBUG]: Running command ['ip', '--oneline', '-6', 'route', 'list', 'table', 'all'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-16 13:02:52,568 - main.py[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2020-07-16 13:02:52,568 - main.py[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early.
2020-07-16 13:02:52,568 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust]
2020-07-16 13:02:52,568 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-07-16 13:02:52,569 - util.py[DEBUG]: Read 4721 bytes from /var/lib/cloud/instance/obj.pkl
2020-07-16 13:02:52,570 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
2020-07-16 13:02:52,570 - util.py[DEBUG]: Read 8 bytes from /run/cloud-init/.instance-id
2020-07-16 13:02:52,570 - stages.py[DEBUG]: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-07-16 13:02:52,570 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-07-16 13:02:52,570 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-07-16 13:02:52,570 - util.py[DEBUG]: Read 2637 bytes from /etc/cloud/cloud.cfg
2020-07-16 13:02:52,570 - util.py[DEBUG]: Attempting to load yaml from string of length 2637 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,576 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-07-16 13:02:52,576 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-07-16 13:02:52,576 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,579 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00_debian.cfg (quiet=False)
2020-07-16 13:02:52,579 - util.py[DEBUG]: Read 93 bytes from /etc/cloud/cloud.cfg.d/00_debian.cfg
2020-07-16 13:02:52,579 - util.py[DEBUG]: Attempting to load yaml from string of length 93 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,579 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-16 13:02:52,580 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-07-16 13:02:52,580 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,580 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,580 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-16 13:02:52,580 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-07-16 13:02:52,580 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/nocloud'
2020-07-16 13:02:52,581 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/nocloud/datasource (quiet=False)
2020-07-16 13:02:52,581 - util.py[DEBUG]: Read 65 bytes from /var/lib/cloud/instances/nocloud/datasource
2020-07-16 13:02:52,581 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/datasource - wb: [644] 65 bytes
2020-07-16 13:02:52,581 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 65 bytes
2020-07-16 13:02:52,581 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-07-16 13:02:52,581 - util.py[DEBUG]: Read 8 bytes from /var/lib/cloud/data/instance-id
2020-07-16 13:02:52,582 - stages.py[DEBUG]: previous iid found to be nocloud
2020-07-16 13:02:52,582 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 8 bytes
2020-07-16 13:02:52,582 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 8 bytes
2020-07-16 13:02:52,582 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 8 bytes
2020-07-16 13:02:52,583 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 4776 bytes
2020-07-16 13:02:52,583 - main.py[DEBUG]: [net] init will now be targeting instance id: nocloud. new=False
2020-07-16 13:02:52,583 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-07-16 13:02:52,583 - util.py[DEBUG]: Read 2637 bytes from /etc/cloud/cloud.cfg
2020-07-16 13:02:52,583 - util.py[DEBUG]: Attempting to load yaml from string of length 2637 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,589 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-07-16 13:02:52,589 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-07-16 13:02:52,589 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,591 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00_debian.cfg (quiet=False)
2020-07-16 13:02:52,591 - util.py[DEBUG]: Read 93 bytes from /etc/cloud/cloud.cfg.d/00_debian.cfg
2020-07-16 13:02:52,592 - util.py[DEBUG]: Attempting to load yaml from string of length 93 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,592 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-16 13:02:52,592 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-07-16 13:02:52,592 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,593 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,593 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-16 13:02:52,593 - util.py[DEBUG]: Reading from /sys/class/net/enp1s0/address (quiet=False)
2020-07-16 13:02:52,593 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/enp1s0/address
2020-07-16 13:02:52,593 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-07-16 13:02:52,594 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-07-16 13:02:52,594 - __init__.py[DEBUG]: Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net] not updated for events: System boot
2020-07-16 13:02:52,594 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update on 'System boot' event
2020-07-16 13:02:52,594 - stages.py[DEBUG]: applying net config names for {'version': 2, 'ethernets': {'main': {'match': {'macaddress': '52:54:00:8c:fc:10'}, 'addresses': ['192.168.122.100'], 'gateway4': '192.168.122.1'}}}
2020-07-16 13:02:52,594 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.debian.Distro'>
2020-07-16 13:02:52,594 - __init__.py[DEBUG]: no interfaces to rename
2020-07-16 13:02:52,594 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource
2020-07-16 13:02:52,594 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource
2020-07-16 13:02:52,594 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt - wb: [600] 656 bytes
2020-07-16 13:02:52,595 - util.py[DEBUG]: Attempting to load yaml from string of length 656 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,598 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt.i - wb: [600] 961 bytes
2020-07-16 13:02:52,598 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data.txt - wb: [600] 0 bytes
2020-07-16 13:02:52,599 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data.txt.i - wb: [600] 308 bytes
2020-07-16 13:02:52,599 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/consume_data - wb: [644] 24 bytes
2020-07-16 13:02:52,599 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/consume_data'>)
2020-07-16 13:02:52,599 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data
2020-07-16 13:02:52,600 - stages.py[DEBUG]: Added default handler for {'text/cloud-config-jsonp', 'text/cloud-config'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2020-07-16 13:02:52,600 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
2020-07-16 13:02:52,600 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
2020-07-16 13:02:52,600 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']]
2020-07-16 13:02:52,600 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
2020-07-16 13:02:52,600 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2020-07-16 13:02:52,600 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2020-07-16 13:02:52,600 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2020-07-16 13:02:52,600 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2020-07-16 13:02:52,600 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance
2020-07-16 13:02:52,600 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Type': 'text/cloud-config', 'Content-Disposition': 'attachment; filename="part-001"'}
2020-07-16 13:02:52,600 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance
2020-07-16 13:02:52,600 - util.py[DEBUG]: Attempting to load yaml from string of length 656 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,602 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])]
2020-07-16 13:02:52,602 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2020-07-16 13:02:52,603 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/cloud-config.txt - wb: [600] 714 bytes
2020-07-16 13:02:52,603 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2020-07-16 13:02:52,603 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2020-07-16 13:02:52,603 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2020-07-16 13:02:52,603 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance
2020-07-16 13:02:52,603 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data
2020-07-16 13:02:52,603 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data
2020-07-16 13:02:52,603 - stages.py[DEBUG]: no vendordata from datasource
2020-07-16 13:02:52,603 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data
2020-07-16 13:02:52,604 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-07-16 13:02:52,604 - util.py[DEBUG]: Read 2637 bytes from /etc/cloud/cloud.cfg
2020-07-16 13:02:52,604 - util.py[DEBUG]: Attempting to load yaml from string of length 2637 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,610 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-07-16 13:02:52,610 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-07-16 13:02:52,610 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,612 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00_debian.cfg (quiet=False)
2020-07-16 13:02:52,612 - util.py[DEBUG]: Read 93 bytes from /etc/cloud/cloud.cfg.d/00_debian.cfg
2020-07-16 13:02:52,612 - util.py[DEBUG]: Attempting to load yaml from string of length 93 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,613 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-16 13:02:52,613 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-07-16 13:02:52,613 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,613 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,613 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-16 13:02:52,613 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-07-16 13:02:52,613 - util.py[DEBUG]: Read 714 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-07-16 13:02:52,613 - util.py[DEBUG]: Attempting to load yaml from string of length 714 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,615 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-07-16 13:02:52,615 - util.py[DEBUG]: Read 714 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-07-16 13:02:52,615 - util.py[DEBUG]: Attempting to load yaml from string of length 714 with allowed root types (<class 'dict'>,)
2020-07-16 13:02:52,624 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource
2020-07-16 13:02:52,625 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 6971 bytes
2020-07-16 13:02:52,625 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource
2020-07-16 13:02:52,626 - main.py[DEBUG]: no di_report found in config.
2020-07-16 13:02:52,655 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.debian.Distro'>
2020-07-16 13:02:52,656 - stages.py[DEBUG]: Running module migrator (<module 'cloudinit.config.cc_migrator' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_migrator.py'>) with frequency always
2020-07-16 13:02:52,656 - handlers.py[DEBUG]: start: init-network/config-migrator: running config-migrator with frequency always
2020-07-16 13:02:52,656 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0x7fd9c7bdab20>)
2020-07-16 13:02:52,656 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2020-07-16 13:02:52,656 - handlers.py[DEBUG]: finish: init-network/config-migrator: SUCCESS: config-migrator ran successfully
2020-07-16 13:02:52,656 - stages.py[DEBUG]: Running module seed_random (<module 'cloudinit.config.cc_seed_random' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_seed_random.py'>) with frequency once-per-instance
2020-07-16 13:02:52,656 - handlers.py[DEBUG]: start: init-network/config-seed_random: running config-seed_random with frequency once-per-instance
2020-07-16 13:02:52,656 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_seed_random - wb: [644] 24 bytes
2020-07-16 13:02:52,657 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_seed_random'>)
2020-07-16 13:02:52,657 - cc_seed_random.py[DEBUG]: no command provided
2020-07-16 13:02:52,657 - handlers.py[DEBUG]: finish: init-network/config-seed_random: SUCCESS: config-seed_random ran successfully
2020-07-16 13:02:52,657 - stages.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_bootcmd.py'>) with frequency always
2020-07-16 13:02:52,657 - handlers.py[DEBUG]: start: init-network/config-bootcmd: running config-bootcmd with frequency always
2020-07-16 13:02:52,657 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x7fd9c7b2d3d0>)
2020-07-16 13:02:52,657 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2020-07-16 13:02:52,657 - handlers.py[DEBUG]: finish: init-network/config-bootcmd: SUCCESS: config-bootcmd ran successfully
2020-07-16 13:02:52,657 - stages.py[DEBUG]: Running module write-files (<module 'cloudinit.config.cc_write_files' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_write_files.py'>) with frequency once-per-instance
2020-07-16 13:02:52,657 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance
2020-07-16 13:02:52,657 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_write_files - wb: [644] 24 bytes
2020-07-16 13:02:52,658 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_write_files'>)
2020-07-16 13:02:52,658 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2020-07-16 13:02:52,658 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files ran successfully
2020-07-16 13:02:52,658 - stages.py[DEBUG]: Running module growpart (<module 'cloudinit.config.cc_growpart' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_growpart.py'>) with frequency always
2020-07-16 13:02:52,658 - handlers.py[DEBUG]: start: init-network/config-growpart: running config-growpart with frequency always
2020-07-16 13:02:52,658 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x7fd9c7b2d250>)
2020-07-16 13:02:52,658 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg. Using default: {'mode': 'auto', 'devices': ['/'], 'ignore_growroot_disabled': False}
2020-07-16 13:02:52,658 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,663 - util.py[DEBUG]: Reading from /proc/414/mountinfo (quiet=False)
2020-07-16 13:02:52,663 - util.py[DEBUG]: Read 3126 bytes from /proc/414/mountinfo
2020-07-16 13:02:52,663 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,667 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,669 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,670 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-07-16 13:02:52,670 - util.py[DEBUG]: Read 145 bytes from /proc/1/environ
2020-07-16 13:02:52,670 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-07-16 13:02:52,670 - util.py[DEBUG]: Read 1035 bytes from /proc/self/status
2020-07-16 13:02:52,670 - util.py[DEBUG]: Reading from /sys/class/block/sda1/partition (quiet=False)
2020-07-16 13:02:52,670 - util.py[DEBUG]: Read 2 bytes from /sys/class/block/sda1/partition
2020-07-16 13:02:52,670 - util.py[DEBUG]: Reading from /sys/devices/pci0000:00/0000:00:02.2/0000:03:00.0/virtio1/host0/target0:0:0/0:0:0:0/block/sda/dev (quiet=False)
2020-07-16 13:02:52,670 - util.py[DEBUG]: Read 4 bytes from /sys/devices/pci0000:00/0000:00:02.2/0000:03:00.0/virtio1/host0/target0:0:0/0:0:0:0/block/sda/dev
2020-07-16 13:02:52,670 - util.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/sda', '1'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,695 - util.py[DEBUG]: resize_devices took 0.032 seconds
2020-07-16 13:02:52,695 - cc_growpart.py[DEBUG]: '/' NOCHANGE: no change necessary (/dev/sda, 1)
2020-07-16 13:02:52,695 - handlers.py[DEBUG]: finish: init-network/config-growpart: SUCCESS: config-growpart ran successfully
2020-07-16 13:02:52,695 - stages.py[DEBUG]: Running module resizefs (<module 'cloudinit.config.cc_resizefs' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_resizefs.py'>) with frequency always
2020-07-16 13:02:52,695 - handlers.py[DEBUG]: start: init-network/config-resizefs: running config-resizefs with frequency always
2020-07-16 13:02:52,695 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x7fd9c7b2d340>)
2020-07-16 13:02:52,735 - util.py[DEBUG]: Reading from /proc/414/mountinfo (quiet=False)
2020-07-16 13:02:52,736 - util.py[DEBUG]: Read 3126 bytes from /proc/414/mountinfo
2020-07-16 13:02:52,736 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/sda1 mnt_point=/ path=/
2020-07-16 13:02:52,736 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,740 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,742 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,743 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-07-16 13:02:52,743 - util.py[DEBUG]: Read 145 bytes from /proc/1/environ
2020-07-16 13:02:52,743 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-07-16 13:02:52,743 - util.py[DEBUG]: Read 1035 bytes from /proc/self/status
2020-07-16 13:02:52,743 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/sda1
2020-07-16 13:02:52,743 - util.py[DEBUG]: Running command ('resize2fs', '/dev/sda1') with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,768 - util.py[DEBUG]: Resizing took 0.025 seconds
2020-07-16 13:02:52,768 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True)
2020-07-16 13:02:52,768 - handlers.py[DEBUG]: finish: init-network/config-resizefs: SUCCESS: config-resizefs ran successfully
2020-07-16 13:02:52,768 - stages.py[DEBUG]: Running module disk_setup (<module 'cloudinit.config.cc_disk_setup' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_disk_setup.py'>) with frequency once-per-instance
2020-07-16 13:02:52,768 - handlers.py[DEBUG]: start: init-network/config-disk_setup: running config-disk_setup with frequency once-per-instance
2020-07-16 13:02:52,768 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_disk_setup - wb: [644] 24 bytes
2020-07-16 13:02:52,769 - helpers.py[DEBUG]: Running config-disk_setup using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_disk_setup'>)
2020-07-16 13:02:52,769 - handlers.py[DEBUG]: finish: init-network/config-disk_setup: SUCCESS: config-disk_setup ran successfully
2020-07-16 13:02:52,769 - stages.py[DEBUG]: Running module mounts (<module 'cloudinit.config.cc_mounts' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_mounts.py'>) with frequency once-per-instance
2020-07-16 13:02:52,769 - handlers.py[DEBUG]: start: init-network/config-mounts: running config-mounts with frequency once-per-instance
2020-07-16 13:02:52,769 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_mounts - wb: [644] 23 bytes
2020-07-16 13:02:52,769 - helpers.py[DEBUG]: Running config-mounts using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_mounts'>)
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: mounts configuration is []
2020-07-16 13:02:52,770 - util.py[DEBUG]: Reading from /etc/fstab (quiet=False)
2020-07-16 13:02:52,770 - util.py[DEBUG]: Read 187 bytes from /etc/fstab
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: changed default device ephemeral0 => None
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount ephemeral0
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: Attempting to determine the real name of swap
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: changed default device swap => None
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount swap
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: no need to setup swap
2020-07-16 13:02:52,770 - cc_mounts.py[DEBUG]: No modifications to fstab needed
2020-07-16 13:02:52,770 - handlers.py[DEBUG]: finish: init-network/config-mounts: SUCCESS: config-mounts ran successfully
2020-07-16 13:02:52,770 - stages.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_set_hostname.py'>) with frequency once-per-instance
2020-07-16 13:02:52,770 - handlers.py[DEBUG]: start: init-network/config-set_hostname: running config-set_hostname with frequency once-per-instance
2020-07-16 13:02:52,770 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_set_hostname - wb: [644] 24 bytes
2020-07-16 13:02:52,771 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_set_hostname'>)
2020-07-16 13:02:52,771 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-07-16 13:02:52,771 - util.py[DEBUG]: Read 109 bytes from /etc/hosts
2020-07-16 13:02:52,771 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-07-16 13:02:52,771 - util.py[DEBUG]: Read 109 bytes from /etc/hosts
2020-07-16 13:02:52,771 - cc_set_hostname.py[DEBUG]: Setting the hostname to debian (debian)
2020-07-16 13:02:52,771 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2020-07-16 13:02:52,771 - util.py[DEBUG]: Read 7 bytes from /etc/hostname
2020-07-16 13:02:52,771 - util.py[DEBUG]: Writing to /etc/hostname - wb: [644] 7 bytes
2020-07-16 13:02:52,771 - __init__.py[DEBUG]: Non-persistently setting the system hostname to debian
2020-07-16 13:02:52,772 - util.py[DEBUG]: Running command ['hostname', 'debian'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:52,773 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/set-hostname (via temporary file /var/lib/cloud/data/tmp9dp42_7k) - w: [644] 45 bytes/chars
2020-07-16 13:02:52,774 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: SUCCESS: config-set_hostname ran successfully
2020-07-16 13:02:52,774 - stages.py[DEBUG]: Running module update_hostname (<module 'cloudinit.config.cc_update_hostname' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_update_hostname.py'>) with frequency always
2020-07-16 13:02:52,774 - handlers.py[DEBUG]: start: init-network/config-update_hostname: running config-update_hostname with frequency always
2020-07-16 13:02:52,774 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x7fd9c8854850>)
2020-07-16 13:02:52,774 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-07-16 13:02:52,774 - util.py[DEBUG]: Read 109 bytes from /etc/hosts
2020-07-16 13:02:52,774 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-07-16 13:02:52,774 - util.py[DEBUG]: Read 109 bytes from /etc/hosts
2020-07-16 13:02:52,774 - cc_update_hostname.py[DEBUG]: Updating hostname to debian (debian)
2020-07-16 13:02:52,774 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2020-07-16 13:02:52,774 - util.py[DEBUG]: Read 7 bytes from /etc/hostname
2020-07-16 13:02:52,774 - __init__.py[DEBUG]: Attempting to update hostname to debian in 1 files
2020-07-16 13:02:52,774 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False)
2020-07-16 13:02:52,775 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-hostname - wb: [644] 7 bytes
2020-07-16 13:02:52,775 - handlers.py[DEBUG]: finish: init-network/config-update_hostname: SUCCESS: config-update_hostname ran successfully
2020-07-16 13:02:52,775 - stages.py[DEBUG]: Running module update_etc_hosts (<module 'cloudinit.config.cc_update_etc_hosts' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_update_etc_hosts.py'>) with frequency always
2020-07-16 13:02:52,775 - handlers.py[DEBUG]: start: init-network/config-update_etc_hosts: running config-update_etc_hosts with frequency always
2020-07-16 13:02:52,775 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x7fd9c8854790>)
2020-07-16 13:02:52,775 - cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts
2020-07-16 13:02:52,775 - handlers.py[DEBUG]: finish: init-network/config-update_etc_hosts: SUCCESS: config-update_etc_hosts ran successfully
2020-07-16 13:02:52,775 - stages.py[DEBUG]: Running module ca-certs (<module 'cloudinit.config.cc_ca_certs' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ca_certs.py'>) with frequency once-per-instance
2020-07-16 13:02:52,775 - handlers.py[DEBUG]: start: init-network/config-ca-certs: running config-ca-certs with frequency once-per-instance
2020-07-16 13:02:52,776 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ca_certs - wb: [644] 24 bytes
2020-07-16 13:02:52,776 - helpers.py[DEBUG]: Running config-ca-certs using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ca_certs'>)
2020-07-16 13:02:52,776 - cc_ca_certs.py[DEBUG]: Skipping module named ca-certs, no 'ca-certs' key in configuration
2020-07-16 13:02:52,776 - handlers.py[DEBUG]: finish: init-network/config-ca-certs: SUCCESS: config-ca-certs ran successfully
2020-07-16 13:02:52,776 - stages.py[DEBUG]: Running module rsyslog (<module 'cloudinit.config.cc_rsyslog' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_rsyslog.py'>) with frequency once-per-instance
2020-07-16 13:02:52,776 - handlers.py[DEBUG]: start: init-network/config-rsyslog: running config-rsyslog with frequency once-per-instance
2020-07-16 13:02:52,776 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_rsyslog - wb: [644] 23 bytes
2020-07-16 13:02:52,776 - helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_rsyslog'>)
2020-07-16 13:02:52,777 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
2020-07-16 13:02:52,777 - handlers.py[DEBUG]: finish: init-network/config-rsyslog: SUCCESS: config-rsyslog ran successfully
2020-07-16 13:02:52,777 - stages.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_users_groups.py'>) with frequency once-per-instance
2020-07-16 13:02:52,777 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance
2020-07-16 13:02:52,777 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_users_groups - wb: [644] 24 bytes
2020-07-16 13:02:52,777 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_users_groups'>)
2020-07-16 13:02:52,777 - util.py[DEBUG]: Reading from /etc/os-release (quiet=True)
2020-07-16 13:02:52,777 - util.py[DEBUG]: Read 200 bytes from /etc/os-release
2020-07-16 13:02:52,778 - util.py[DEBUG]: Reading from /etc/system-image/channel.ini (quiet=True)
2020-07-16 13:02:52,778 - util.py[DEBUG]: Read 0 bytes from /etc/system-image/channel.ini
2020-07-16 13:02:52,778 - __init__.py[DEBUG]: Adding user foo
2020-07-16 13:02:52,778 - util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['useradd', 'foo', '--password', 'REDACTED', '--shell', '/bin/bash', '-m']
2020-07-16 13:02:52,924 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False)
2020-07-16 13:02:52,925 - util.py[DEBUG]: Read 669 bytes from /etc/sudoers
2020-07-16 13:02:52,926 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - wb: [440] 116 bytes
2020-07-16 13:02:52,926 - util.py[DEBUG]: Changing the ownership of /home/foo/.ssh to 1000:1000
2020-07-16 13:02:52,927 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-07-16 13:02:52,927 - util.py[DEBUG]: Read 3311 bytes from /etc/ssh/sshd_config
2020-07-16 13:02:52,928 - util.py[DEBUG]: Writing to /home/foo/.ssh/authorized_keys - wb: [600] 408 bytes
2020-07-16 13:02:52,928 - util.py[DEBUG]: Changing the ownership of /home/foo/.ssh/authorized_keys to 1000:1000
2020-07-16 13:02:52,928 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups ran successfully
2020-07-16 13:02:52,928 - stages.py[DEBUG]: Running module ssh (<module 'cloudinit.config.cc_ssh' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh.py'>) with frequency once-per-instance
2020-07-16 13:02:52,928 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance
2020-07-16 13:02:52,928 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh - wb: [644] 24 bytes
2020-07-16 13:02:52,929 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh'>)
2020-07-16 13:02:52,929 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,120 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'dsa', '-N', '', '-f', '/etc/ssh/ssh_host_dsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,181 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ecdsa', '-N', '', '-f', '/etc/ssh/ssh_host_ecdsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,185 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ed25519', '-N', '', '-f', '/etc/ssh/ssh_host_ed25519_key'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,190 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ed25519_key.pub (quiet=False)
2020-07-16 13:02:53,190 - util.py[DEBUG]: Read 93 bytes from /etc/ssh/ssh_host_ed25519_key.pub
2020-07-16 13:02:53,190 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ecdsa_key.pub (quiet=False)
2020-07-16 13:02:53,190 - util.py[DEBUG]: Read 173 bytes from /etc/ssh/ssh_host_ecdsa_key.pub
2020-07-16 13:02:53,190 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_rsa_key.pub (quiet=False)
2020-07-16 13:02:53,190 - util.py[DEBUG]: Read 565 bytes from /etc/ssh/ssh_host_rsa_key.pub
2020-07-16 13:02:53,191 - util.py[DEBUG]: Changing the ownership of /root/.ssh to 0:0
2020-07-16 13:02:53,191 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-07-16 13:02:53,191 - util.py[DEBUG]: Read 3311 bytes from /etc/ssh/sshd_config
2020-07-16 13:02:53,191 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 0 bytes
2020-07-16 13:02:53,192 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2020-07-16 13:02:53,192 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh ran successfully
2020-07-16 13:02:53,192 - main.py[DEBUG]: Ran 15 modules with 0 failures
2020-07-16 13:02:53,192 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpz1o16gzo) - w: [644] 545 bytes/chars
2020-07-16 13:02:53,192 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-07-16 13:02:53,193 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-07-16 13:02:53,193 - util.py[DEBUG]: cloud-init mode 'init' took 0.665 seconds (0.67)
2020-07-16 13:02:53,193 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources
2020-07-16 13:02:53,554 - util.py[DEBUG]: Cloud-init v. 20.2 running 'modules:config' at Thu, 16 Jul 2020 13:02:53 +0000. Up 12.67 seconds.
2020-07-16 13:02:53,570 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.debian.Distro'>
2020-07-16 13:02:53,570 - stages.py[DEBUG]: Running module emit_upstart (<module 'cloudinit.config.cc_emit_upstart' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_emit_upstart.py'>) with frequency always
2020-07-16 13:02:53,571 - handlers.py[DEBUG]: start: modules-config/config-emit_upstart: running config-emit_upstart with frequency always
2020-07-16 13:02:53,571 - helpers.py[DEBUG]: Running config-emit_upstart using lock (<cloudinit.helpers.DummyLock object at 0x7f00e776b580>)
2020-07-16 13:02:53,571 - cc_emit_upstart.py[DEBUG]: no /sbin/initctl located
2020-07-16 13:02:53,571 - cc_emit_upstart.py[DEBUG]: not upstart system, 'emit_upstart' disabled
2020-07-16 13:02:53,571 - handlers.py[DEBUG]: finish: modules-config/config-emit_upstart: SUCCESS: config-emit_upstart ran successfully
2020-07-16 13:02:53,571 - stages.py[DEBUG]: Running module ssh-import-id (<module 'cloudinit.config.cc_ssh_import_id' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_import_id.py'>) with frequency once-per-instance
2020-07-16 13:02:53,571 - handlers.py[DEBUG]: start: modules-config/config-ssh-import-id: running config-ssh-import-id with frequency once-per-instance
2020-07-16 13:02:53,571 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh_import_id - wb: [644] 23 bytes
2020-07-16 13:02:53,571 - helpers.py[DEBUG]: Running config-ssh-import-id using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh_import_id'>)
2020-07-16 13:02:53,572 - cc_ssh_import_id.py[DEBUG]: User foo is not configured for ssh_import_id
2020-07-16 13:02:53,572 - handlers.py[DEBUG]: finish: modules-config/config-ssh-import-id: SUCCESS: config-ssh-import-id ran successfully
2020-07-16 13:02:53,572 - stages.py[DEBUG]: Running module locale (<module 'cloudinit.config.cc_locale' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_locale.py'>) with frequency once-per-instance
2020-07-16 13:02:53,572 - handlers.py[DEBUG]: start: modules-config/config-locale: running config-locale with frequency once-per-instance
2020-07-16 13:02:53,572 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_locale - wb: [644] 24 bytes
2020-07-16 13:02:53,572 - helpers.py[DEBUG]: Running config-locale using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_locale'>)
2020-07-16 13:02:53,572 - util.py[DEBUG]: Reading from /etc/default/locale (quiet=False)
2020-07-16 13:02:53,572 - util.py[DEBUG]: Read 13 bytes from /etc/default/locale
2020-07-16 13:02:53,573 - cc_locale.py[DEBUG]: Setting locale to C.UTF-8
2020-07-16 13:02:53,573 - debian.py[DEBUG]: System has 'LANG=C.UTF-8' requested 'C.UTF-8', skipping regeneration.
2020-07-16 13:02:53,573 - handlers.py[DEBUG]: finish: modules-config/config-locale: SUCCESS: config-locale ran successfully
2020-07-16 13:02:53,573 - stages.py[DEBUG]: Running module set-passwords (<module 'cloudinit.config.cc_set_passwords' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_set_passwords.py'>) with frequency once-per-instance
2020-07-16 13:02:53,573 - handlers.py[DEBUG]: start: modules-config/config-set-passwords: running config-set-passwords with frequency once-per-instance
2020-07-16 13:02:53,573 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_set_passwords - wb: [644] 24 bytes
2020-07-16 13:02:53,573 - helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_set_passwords'>)
2020-07-16 13:02:53,573 - cc_set_passwords.py[DEBUG]: Leaving SSH config 'PasswordAuthentication' unchanged. ssh_pwauth=None
2020-07-16 13:02:53,573 - handlers.py[DEBUG]: finish: modules-config/config-set-passwords: SUCCESS: config-set-passwords ran successfully
2020-07-16 13:02:53,573 - stages.py[DEBUG]: Running module grub-dpkg (<module 'cloudinit.config.cc_grub_dpkg' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_grub_dpkg.py'>) with frequency once-per-instance
2020-07-16 13:02:53,573 - handlers.py[DEBUG]: start: modules-config/config-grub-dpkg: running config-grub-dpkg with frequency once-per-instance
2020-07-16 13:02:53,574 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_grub_dpkg - wb: [644] 24 bytes
2020-07-16 13:02:53,574 - helpers.py[DEBUG]: Running config-grub-dpkg using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_grub_dpkg'>)
2020-07-16 13:02:53,574 - cc_grub_dpkg.py[DEBUG]: Setting grub debconf-set-selections with '/dev/sda','false'
2020-07-16 13:02:53,574 - util.py[DEBUG]: Running command ['debconf-set-selections'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,716 - handlers.py[DEBUG]: finish: modules-config/config-grub-dpkg: SUCCESS: config-grub-dpkg ran successfully
2020-07-16 13:02:53,716 - stages.py[DEBUG]: Running module apt-pipelining (<module 'cloudinit.config.cc_apt_pipelining' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_apt_pipelining.py'>) with frequency once-per-instance
2020-07-16 13:02:53,716 - handlers.py[DEBUG]: start: modules-config/config-apt-pipelining: running config-apt-pipelining with frequency once-per-instance
2020-07-16 13:02:53,716 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_apt_pipelining - wb: [644] 24 bytes
2020-07-16 13:02:53,717 - helpers.py[DEBUG]: Running config-apt-pipelining using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_apt_pipelining'>)
2020-07-16 13:02:53,717 - handlers.py[DEBUG]: finish: modules-config/config-apt-pipelining: SUCCESS: config-apt-pipelining ran successfully
2020-07-16 13:02:53,717 - stages.py[DEBUG]: Running module apt-configure (<module 'cloudinit.config.cc_apt_configure' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_apt_configure.py'>) with frequency once-per-instance
2020-07-16 13:02:53,717 - handlers.py[DEBUG]: start: modules-config/config-apt-configure: running config-apt-configure with frequency once-per-instance
2020-07-16 13:02:53,717 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_apt_configure - wb: [644] 23 bytes
2020-07-16 13:02:53,717 - helpers.py[DEBUG]: Running config-apt-configure using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_apt_configure'>)
2020-07-16 13:02:53,717 - cc_apt_configure.py[DEBUG]: apt config: convert V2 to V3 format for keys 'apt_preserve_sources_list'
2020-07-16 13:02:53,717 - cc_apt_configure.py[DEBUG]: debconf_selections was not set in config
2020-07-16 13:02:53,717 - cc_apt_configure.py[DEBUG]: handling apt config: {'preserve_sources_list': True}
2020-07-16 13:02:53,717 - util.py[DEBUG]: Running command ['lsb_release', '--all'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,774 - util.py[DEBUG]: Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,777 - cc_apt_configure.py[DEBUG]: got primary mirror: None
2020-07-16 13:02:53,777 - cc_apt_configure.py[DEBUG]: got security mirror: None
2020-07-16 13:02:53,777 - util.py[DEBUG]: Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:53,779 - __init__.py[DEBUG]: filtered distro mirror info: {'primary': 'http://deb.debian.org/debian', 'security': 'http://security.debian.org/'}
2020-07-16 13:02:53,779 - cc_apt_configure.py[DEBUG]: Apt Mirror info: {'primary': 'http://deb.debian.org/debian', 'security': 'http://security.debian.org/', 'PRIMARY': 'http://deb.debian.org/debian', 'SECURITY': 'http://security.debian.org/', 'MIRROR': 'http://deb.debian.org/debian'}
2020-07-16 13:02:53,780 - handlers.py[DEBUG]: finish: modules-config/config-apt-configure: SUCCESS: config-apt-configure ran successfully
2020-07-16 13:02:53,780 - stages.py[DEBUG]: Running module ntp (<module 'cloudinit.config.cc_ntp' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ntp.py'>) with frequency once-per-instance
2020-07-16 13:02:53,780 - handlers.py[DEBUG]: start: modules-config/config-ntp: running config-ntp with frequency once-per-instance
2020-07-16 13:02:53,780 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ntp - wb: [644] 24 bytes
2020-07-16 13:02:53,780 - helpers.py[DEBUG]: Running config-ntp using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ntp'>)
2020-07-16 13:02:53,780 - cc_ntp.py[DEBUG]: Skipping module named ntp, not present or disabled by cfg
2020-07-16 13:02:53,780 - handlers.py[DEBUG]: finish: modules-config/config-ntp: SUCCESS: config-ntp ran successfully
2020-07-16 13:02:53,780 - stages.py[DEBUG]: Running module timezone (<module 'cloudinit.config.cc_timezone' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_timezone.py'>) with frequency once-per-instance
2020-07-16 13:02:53,781 - handlers.py[DEBUG]: start: modules-config/config-timezone: running config-timezone with frequency once-per-instance
2020-07-16 13:02:53,781 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_timezone - wb: [644] 24 bytes
2020-07-16 13:02:53,781 - helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_timezone'>)
2020-07-16 13:02:53,781 - cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified
2020-07-16 13:02:53,781 - handlers.py[DEBUG]: finish: modules-config/config-timezone: SUCCESS: config-timezone ran successfully
2020-07-16 13:02:53,781 - stages.py[DEBUG]: Running module disable-ec2-metadata (<module 'cloudinit.config.cc_disable_ec2_metadata' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_disable_ec2_metadata.py'>) with frequency always
2020-07-16 13:02:53,781 - handlers.py[DEBUG]: start: modules-config/config-disable-ec2-metadata: running config-disable-ec2-metadata with frequency always
2020-07-16 13:02:53,781 - helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock (<cloudinit.helpers.DummyLock object at 0x7f00e7787fd0>)
2020-07-16 13:02:53,781 - cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled
2020-07-16 13:02:53,781 - handlers.py[DEBUG]: finish: modules-config/config-disable-ec2-metadata: SUCCESS: config-disable-ec2-metadata ran successfully
2020-07-16 13:02:53,781 - stages.py[DEBUG]: Running module runcmd (<module 'cloudinit.config.cc_runcmd' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_runcmd.py'>) with frequency once-per-instance
2020-07-16 13:02:53,782 - handlers.py[DEBUG]: start: modules-config/config-runcmd: running config-runcmd with frequency once-per-instance
2020-07-16 13:02:53,782 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_runcmd - wb: [644] 24 bytes
2020-07-16 13:02:53,782 - helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_runcmd'>)
2020-07-16 13:02:53,782 - cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration
2020-07-16 13:02:53,782 - handlers.py[DEBUG]: finish: modules-config/config-runcmd: SUCCESS: config-runcmd ran successfully
2020-07-16 13:02:53,782 - stages.py[DEBUG]: Running module byobu (<module 'cloudinit.config.cc_byobu' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_byobu.py'>) with frequency once-per-instance
2020-07-16 13:02:53,782 - handlers.py[DEBUG]: start: modules-config/config-byobu: running config-byobu with frequency once-per-instance
2020-07-16 13:02:53,782 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_byobu - wb: [644] 24 bytes
2020-07-16 13:02:53,782 - helpers.py[DEBUG]: Running config-byobu using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_byobu'>)
2020-07-16 13:02:53,782 - cc_byobu.py[DEBUG]: Skipping module named byobu, no 'byobu' values found
2020-07-16 13:02:53,783 - handlers.py[DEBUG]: finish: modules-config/config-byobu: SUCCESS: config-byobu ran successfully
2020-07-16 13:02:53,783 - main.py[DEBUG]: Ran 12 modules with 0 failures
2020-07-16 13:02:53,783 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpw796ivhj) - w: [644] 572 bytes/chars
2020-07-16 13:02:53,783 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-07-16 13:02:53,783 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-07-16 13:02:53,783 - util.py[DEBUG]: cloud-init mode 'modules' took 0.277 seconds (0.28)
2020-07-16 13:02:53,783 - handlers.py[DEBUG]: finish: modules-config: SUCCESS: running modules for config
2020-07-16 13:02:54,047 - util.py[DEBUG]: Cloud-init v. 20.2 running 'modules:final' at Thu, 16 Jul 2020 13:02:54 +0000. Up 13.18 seconds.
2020-07-16 13:02:54,062 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.debian.Distro'>
2020-07-16 13:02:54,063 - stages.py[DEBUG]: Running module package-update-upgrade-install (<module 'cloudinit.config.cc_package_update_upgrade_install' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_package_update_upgrade_install.py'>) with frequency once-per-instance
2020-07-16 13:02:54,063 - handlers.py[DEBUG]: start: modules-final/config-package-update-upgrade-install: running config-package-update-upgrade-install with frequency once-per-instance
2020-07-16 13:02:54,063 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_package_update_upgrade_install - wb: [644] 24 bytes
2020-07-16 13:02:54,063 - helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_package_update_upgrade_install'>)
2020-07-16 13:02:54,064 - handlers.py[DEBUG]: finish: modules-final/config-package-update-upgrade-install: SUCCESS: config-package-update-upgrade-install ran successfully
2020-07-16 13:02:54,064 - stages.py[DEBUG]: Running module fan (<module 'cloudinit.config.cc_fan' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_fan.py'>) with frequency once-per-instance
2020-07-16 13:02:54,064 - handlers.py[DEBUG]: start: modules-final/config-fan: running config-fan with frequency once-per-instance
2020-07-16 13:02:54,064 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_fan - wb: [644] 24 bytes
2020-07-16 13:02:54,064 - helpers.py[DEBUG]: Running config-fan using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_fan'>)
2020-07-16 13:02:54,064 - cc_fan.py[DEBUG]: fan: no 'fan' config entry. disabling
2020-07-16 13:02:54,064 - handlers.py[DEBUG]: finish: modules-final/config-fan: SUCCESS: config-fan ran successfully
2020-07-16 13:02:54,064 - stages.py[DEBUG]: Running module puppet (<module 'cloudinit.config.cc_puppet' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_puppet.py'>) with frequency once-per-instance
2020-07-16 13:02:54,064 - handlers.py[DEBUG]: start: modules-final/config-puppet: running config-puppet with frequency once-per-instance
2020-07-16 13:02:54,065 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_puppet - wb: [644] 24 bytes
2020-07-16 13:02:54,065 - helpers.py[DEBUG]: Running config-puppet using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_puppet'>)
2020-07-16 13:02:54,065 - cc_puppet.py[DEBUG]: Skipping module named puppet, no 'puppet' configuration found
2020-07-16 13:02:54,065 - handlers.py[DEBUG]: finish: modules-final/config-puppet: SUCCESS: config-puppet ran successfully
2020-07-16 13:02:54,065 - stages.py[DEBUG]: Running module chef (<module 'cloudinit.config.cc_chef' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_chef.py'>) with frequency once-per-instance
2020-07-16 13:02:54,065 - handlers.py[DEBUG]: start: modules-final/config-chef: running config-chef with frequency once-per-instance
2020-07-16 13:02:54,065 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_chef - wb: [644] 24 bytes
2020-07-16 13:02:54,065 - helpers.py[DEBUG]: Running config-chef using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_chef'>)
2020-07-16 13:02:54,065 - cc_chef.py[DEBUG]: Skipping module named chef, no 'chef' key in configuration
2020-07-16 13:02:54,066 - handlers.py[DEBUG]: finish: modules-final/config-chef: SUCCESS: config-chef ran successfully
2020-07-16 13:02:54,066 - stages.py[DEBUG]: Running module salt-minion (<module 'cloudinit.config.cc_salt_minion' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_salt_minion.py'>) with frequency once-per-instance
2020-07-16 13:02:54,066 - handlers.py[DEBUG]: start: modules-final/config-salt-minion: running config-salt-minion with frequency once-per-instance
2020-07-16 13:02:54,066 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_salt_minion - wb: [644] 24 bytes
2020-07-16 13:02:54,066 - helpers.py[DEBUG]: Running config-salt-minion using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_salt_minion'>)
2020-07-16 13:02:54,066 - cc_salt_minion.py[DEBUG]: Skipping module named salt-minion, no 'salt_minion' key in configuration
2020-07-16 13:02:54,066 - handlers.py[DEBUG]: finish: modules-final/config-salt-minion: SUCCESS: config-salt-minion ran successfully
2020-07-16 13:02:54,066 - stages.py[DEBUG]: Running module mcollective (<module 'cloudinit.config.cc_mcollective' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_mcollective.py'>) with frequency once-per-instance
2020-07-16 13:02:54,066 - handlers.py[DEBUG]: start: modules-final/config-mcollective: running config-mcollective with frequency once-per-instance
2020-07-16 13:02:54,066 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_mcollective - wb: [644] 23 bytes
2020-07-16 13:02:54,067 - helpers.py[DEBUG]: Running config-mcollective using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_mcollective'>)
2020-07-16 13:02:54,067 - cc_mcollective.py[DEBUG]: Skipping module named mcollective, no 'mcollective' key in configuration
2020-07-16 13:02:54,067 - handlers.py[DEBUG]: finish: modules-final/config-mcollective: SUCCESS: config-mcollective ran successfully
2020-07-16 13:02:54,067 - stages.py[DEBUG]: Running module rightscale_userdata (<module 'cloudinit.config.cc_rightscale_userdata' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_rightscale_userdata.py'>) with frequency once-per-instance
2020-07-16 13:02:54,067 - handlers.py[DEBUG]: start: modules-final/config-rightscale_userdata: running config-rightscale_userdata with frequency once-per-instance
2020-07-16 13:02:54,067 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_rightscale_userdata - wb: [644] 24 bytes
2020-07-16 13:02:54,067 - helpers.py[DEBUG]: Running config-rightscale_userdata using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_rightscale_userdata'>)
2020-07-16 13:02:54,067 - cc_rightscale_userdata.py[DEBUG]: Failed to get raw userdata in module rightscale_userdata
2020-07-16 13:02:54,067 - handlers.py[DEBUG]: finish: modules-final/config-rightscale_userdata: SUCCESS: config-rightscale_userdata ran successfully
2020-07-16 13:02:54,067 - stages.py[DEBUG]: Running module scripts-vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_vendor.py'>) with frequency once-per-instance
2020-07-16 13:02:54,068 - handlers.py[DEBUG]: start: modules-final/config-scripts-vendor: running config-scripts-vendor with frequency once-per-instance
2020-07-16 13:02:54,068 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_vendor - wb: [644] 22 bytes
2020-07-16 13:02:54,068 - helpers.py[DEBUG]: Running config-scripts-vendor using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_vendor'>)
2020-07-16 13:02:54,068 - handlers.py[DEBUG]: finish: modules-final/config-scripts-vendor: SUCCESS: config-scripts-vendor ran successfully
2020-07-16 13:02:54,068 - stages.py[DEBUG]: Running module scripts-per-once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once
2020-07-16 13:02:54,068 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once
2020-07-16 13:02:54,068 - util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [644] 23 bytes
2020-07-16 13:02:54,068 - helpers.py[DEBUG]: Running config-scripts-per-once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>)
2020-07-16 13:02:54,069 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once ran successfully
2020-07-16 13:02:54,069 - stages.py[DEBUG]: Running module scripts-per-boot (<module 'cloudinit.config.cc_scripts_per_boot' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_per_boot.py'>) with frequency always
2020-07-16 13:02:54,069 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always
2020-07-16 13:02:54,069 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x7f3786345c10>)
2020-07-16 13:02:54,069 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully
2020-07-16 13:02:54,069 - stages.py[DEBUG]: Running module scripts-per-instance (<module 'cloudinit.config.cc_scripts_per_instance' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_per_instance.py'>) with frequency once-per-instance
2020-07-16 13:02:54,069 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance
2020-07-16 13:02:54,069 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_per_instance - wb: [644] 24 bytes
2020-07-16 13:02:54,069 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_per_instance'>)
2020-07-16 13:02:54,069 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance ran successfully
2020-07-16 13:02:54,069 - stages.py[DEBUG]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance
2020-07-16 13:02:54,070 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance
2020-07-16 13:02:54,070 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_user - wb: [644] 24 bytes
2020-07-16 13:02:54,070 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_user'>)
2020-07-16 13:02:54,070 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully
2020-07-16 13:02:54,070 - stages.py[DEBUG]: 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'>) with frequency once-per-instance
2020-07-16 13:02:54,070 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance
2020-07-16 13:02:54,070 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints - wb: [644] 23 bytes
2020-07-16 13:02:54,071 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints'>)
2020-07-16 13:02:54,071 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-07-16 13:02:54,071 - util.py[DEBUG]: Read 3311 bytes from /etc/ssh/sshd_config
2020-07-16 13:02:54,071 - util.py[DEBUG]: Reading from /home/foo/.ssh/authorized_keys (quiet=False)
2020-07-16 13:02:54,071 - util.py[DEBUG]: Read 408 bytes from /home/foo/.ssh/authorized_keys
2020-07-16 13:02:54,078 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully
2020-07-16 13:02:54,078 - stages.py[DEBUG]: Running module keys-to-console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance
2020-07-16 13:02:54,079 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance
2020-07-16 13:02:54,079 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_keys_to_console - wb: [644] 22 bytes
2020-07-16 13:02:54,079 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_keys_to_console'>)
2020-07-16 13:02:54,079 - util.py[DEBUG]: Running command ['/usr/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True)
2020-07-16 13:02:54,104 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully
2020-07-16 13:02:54,104 - stages.py[DEBUG]: Running module phone-home (<module 'cloudinit.config.cc_phone_home' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_phone_home.py'>) with frequency once-per-instance
2020-07-16 13:02:54,105 - handlers.py[DEBUG]: start: modules-final/config-phone-home: running config-phone-home with frequency once-per-instance
2020-07-16 13:02:54,105 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_phone_home - wb: [644] 24 bytes
2020-07-16 13:02:54,105 - helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_phone_home'>)
2020-07-16 13:02:54,105 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
2020-07-16 13:02:54,105 - handlers.py[DEBUG]: finish: modules-final/config-phone-home: SUCCESS: config-phone-home ran successfully
2020-07-16 13:02:54,105 - stages.py[DEBUG]: Running module final-message (<module 'cloudinit.config.cc_final_message' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_final_message.py'>) with frequency always
2020-07-16 13:02:54,106 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always
2020-07-16 13:02:54,106 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x7f3786333580>)
2020-07-16 13:02:54,106 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-07-16 13:02:54,106 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-07-16 13:02:54,108 - util.py[DEBUG]: Cloud-init v. 20.2 finished at Thu, 16 Jul 2020 13:02:54 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net]. Up 13.27 seconds
2020-07-16 13:02:54,108 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 50 bytes
2020-07-16 13:02:54,109 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully
2020-07-16 13:02:54,109 - stages.py[DEBUG]: Running module power-state-change (<module 'cloudinit.config.cc_power_state_change' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_power_state_change.py'>) with frequency once-per-instance
2020-07-16 13:02:54,109 - handlers.py[DEBUG]: start: modules-final/config-power-state-change: running config-power-state-change with frequency once-per-instance
2020-07-16 13:02:54,109 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_power_state_change - wb: [644] 24 bytes
2020-07-16 13:02:54,109 - helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_power_state_change'>)
2020-07-16 13:02:54,109 - cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing
2020-07-16 13:02:54,110 - handlers.py[DEBUG]: finish: modules-final/config-power-state-change: SUCCESS: config-power-state-change ran successfully
2020-07-16 13:02:54,110 - main.py[DEBUG]: Ran 17 modules with 0 failures
2020-07-16 13:02:54,110 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp4rygq1gf) - w: [644] 600 bytes/chars
2020-07-16 13:02:54,110 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmpp8tbzbyn) - w: [644] 96 bytes/chars
2020-07-16 13:02:54,110 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
2020-07-16 13:02:54,110 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-07-16 13:02:54,110 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-07-16 13:02:54,110 - util.py[DEBUG]: cloud-init mode 'modules' took 0.100 seconds (0.11)
2020-07-16 13:02:54,111 - handlers.py[DEBUG]: finish: modules-final: SUCCESS: running modules for final
Cloud-init v. 20.2 running 'init-local' at Thu, 16 Jul 2020 13:02:42 +0000. Up 1.99 seconds. Cloud-init v. 20.2 running 'init' at Thu, 16 Jul 2020 13:02:52 +0000. Up 11.70 seconds. ci-info: ++++++++++++++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++++++++++++ ci-info: +--------+------+----------------------------+---------------+--------+-------------------+ ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | ci-info: +--------+------+----------------------------+---------------+--------+-------------------+ ci-info: | enp1s0 | True | 192.168.122.153 | 255.255.255.0 | global | 52:54:00:8c:fc:10 | ci-info: | enp1s0 | True | fe80::5054:ff:fe8c:fc10/64 | . | link | 52:54:00:8c:fc:10 | ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | ci-info: | lo | True | ::1/128 | . | host | . | ci-info: +--------+------+----------------------------+---------------+--------+-------------------+ ci-info: +++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++ ci-info: +-------+---------------+---------------+---------------+-----------+-------+ ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | ci-info: +-------+---------------+---------------+---------------+-----------+-------+ ci-info: | 0 | 0.0.0.0 | 192.168.122.1 | 0.0.0.0 | enp1s0 | UG | ci-info: | 1 | 192.168.122.0 | 0.0.0.0 | 255.255.255.0 | enp1s0 | U | ci-info: +-------+---------------+---------------+---------------+-----------+-------+ ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ ci-info: +-------+-------------+---------+-----------+-------+ ci-info: | Route | Destination | Gateway | Interface | Flags | ci-info: +-------+-------------+---------+-----------+-------+ ci-info: | 1 | fe80::/64 | :: | enp1s0 | U | ci-info: | 3 | local | :: | enp1s0 | U | ci-info: | 4 | ff00::/8 | :: | enp1s0 | U | ci-info: +-------+-------------+---------+-----------+-------+ Generating public/private rsa key pair. Your identification has been saved in /etc/ssh/ssh_host_rsa_key Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub The key fingerprint is: SHA256:FagMh6dgMhIWQ+/W3HQZPhuHmJc1aYA7O5Uex89TwE8 root@debian The key's randomart image is: +---[RSA 3072]----+ |o*. . .+ooo | |= = o o.= *+.o E | |.+ o * =.X=. + | | . + =oo==o o | | o o .S.o o . | | . o . + | | . . | | | | | +----[SHA256]-----+ Generating public/private dsa key pair. Your identification has been saved in /etc/ssh/ssh_host_dsa_key Your public key has been saved in /etc/ssh/ssh_host_dsa_key.pub The key fingerprint is: SHA256:3dcd8n+UKYCz49Am8SOPGYxtzBZtlBG6iqKTbX4NA/M root@debian The key's randomart image is: +---[DSA 1024]----+ | ++ | | +.. | | + = . . . | | o * B.o.. o.=| | + . &SB. ...++| | E + @ o ....| | + . = o o o| |+ + . . .| |.+.. | +----[SHA256]-----+ Generating public/private ecdsa key pair. Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub The key fingerprint is: SHA256:WgL3onnzOgBeNdaF/U0/ejhw682+4FOpvjWKmS5YdPY root@debian The key's randomart image is: +---[ECDSA 256]---+ | . +. | | + o . . | | .o.. . o . | | . .o . . +.....| | . o o S o + + o| | . .o = . E + | | o.+ o ..Bo | | ..+ . =++o.| | .o. o=.=+o.| +----[SHA256]-----+ Generating public/private ed25519 key pair. Your identification has been saved in /etc/ssh/ssh_host_ed25519_key Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub The key fingerprint is: SHA256:01UremZS8qVLS/9+tgQNXOtGY2761DSD+uW/tUonymA root@debian The key's randomart image is: +--[ED25519 256]--+ | .. | | .....| | . +oo= | | . * +O .| | S + Oo O.| | . B.+=.+| | E .o+.=o| | . o + O.=| | o o.OO| +----[SHA256]-----+ Cloud-init v. 20.2 running 'modules:config' at Thu, 16 Jul 2020 13:02:53 +0000. Up 12.67 seconds. Cloud-init v. 20.2 running 'modules:final' at Thu, 16 Jul 2020 13:02:54 +0000. Up 13.18 seconds. Cloud-init v. 20.2 finished at Thu, 16 Jul 2020 13:02:54 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net]. Up 13.27 seconds
#cloud-config users: - name: foo sudo: ALL=(ALL) NOPASSWD:ALL passwd: $6$AUcK0WG1wk3IvvJQ$jIhwiJkvlf8oSTuviqWiCEl7mXfmlIxluDbFh3XV2BdpeCYGPMCwUjvLzOr92rq4UZRp/O2.iFR33xYr5K4WR/ lock_passwd: false shell: /bin/bash ssh_authorized_keys: - ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDsigSBPsp9N6ZjhTl2fN5dpm00B8pIQjBMZALtg42qyeC4tjX2LfZfeE1iCqZeytpFqCzWiTMN30J24tsGTQWbXbvmW7wDM6pkzT71BnAXED4X6Woc064KFahKi3dQvn5PWxH2FFqXcIGS/+vWhOMzcg2B8u8llQ7lkckg2E6LD48EJnbfsuGoqMADFxWtw5itBzGyAQj94i98tbRNuomiLotSxiB7s7XCtvI8SYehfQhGsFBDKQ3dgzd3wDQNEz1v1RgwlOcDFvTmodShEI4FZgl5tO4dbzVJR5F0ddUW6KHLlK1BlyswVDuYWnnhv5Qahg6eJn323hS/eRlkcp7l sven.bartscher@credativ.de
Attachment:
meta-data
Description: inode/empty
version: 2
ethernets:
main:
match:
macaddress: "52:54:00:8c:fc:10"
addresses: ["192.168.122.100"]
gateway4: "192.168.122.1"