Attachment 19561 Details for Bug 56022 – /var/log/cloud-init.log

/var/log/cloud-init.log

cloud-init.log (text/x-log), 96.45 KB, created by Надежда on 2025-09-17 13:52:12 MSK

(hide)

Description:

Filename:

MIME Type:

Creator: Надежда

Created: 2025-09-17 13:52:12 MSK

Size: 96.45 KB

patch

obsolete

>2025-09-17 10:38:55,855 - log_util.py[DEBUG]: Cloud-init v. 25.1.4 running 'init-local' at Wed, 17 Sep 2025 10:38:55 +0000. Up 7.87 seconds.
>2025-09-17 10:38:55,855 - main.py[INFO]: PID [1] started cloud-init 'init-local'.
>2025-09-17 10:38:55,855 - main.py[DEBUG]: No kernel command line url found.
>2025-09-17 10:38:55,855 - main.py[DEBUG]: Closing stdin
>2025-09-17 10:38:55,858 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [640] 0 bytes
>2025-09-17 10:38:55,858 - util.py[DEBUG]: Writing to /var/lib/cloud/data/python-version - wb: [644] 3 bytes
>2025-09-17 10:38:55,859 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
>2025-09-17 10:38:55,859 - handlers.py[DEBUG]: start: init-local/check-cache: attempting to read from cache [check]
>2025-09-17 10:38:55,859 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
>2025-09-17 10:38:55,859 - stages.py[DEBUG]: no cache found
>2025-09-17 10:38:55,859 - handlers.py[DEBUG]: finish: init-local/check-cache: SUCCESS: no cache found
>2025-09-17 10:38:55,861 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.altlinux.Distro'>
>2025-09-17 10:38:55,862 - sources[DEBUG]: Looking for data source in: ['NoCloud', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
>2025-09-17 10:38:55,864 - sources[DEBUG]: Searching for local data source in: ['DataSourceNoCloud']
>2025-09-17 10:38:55,864 - handlers.py[DEBUG]: start: init-local/search-NoCloud: searching for local data from DataSourceNoCloud
>2025-09-17 10:38:55,864 - sources[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceNoCloud.DataSourceNoCloud'>
>2025-09-17 10:38:55,864 - sources[DEBUG]: Update datasource metadata and network config due to events: boot-new-instance
>2025-09-17 10:38:55,865 - sources[DEBUG]: Detected DataSourceNoCloud 
>2025-09-17 10:38:55,865 - dmi.py[DEBUG]: querying dmi data /sys/class/dmi/id/product_serial
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/user-data (quiet=False)
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/meta-data (quiet=False)
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/vendor-data (quiet=False)
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/network-config (quiet=False)
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/user-data (quiet=False)
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/meta-data (quiet=False)
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/vendor-data (quiet=False)
>2025-09-17 10:38:55,865 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/network-config (quiet=False)
>2025-09-17 10:38:55,866 - subp.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
>2025-09-17 10:38:55,881 - performance.py[DEBUG]: Running ['blkid', '-tTYPE=vfat', '-odevice'] took 0.016 seconds
>2025-09-17 10:38:55,882 - subp.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
>2025-09-17 10:38:55,894 - performance.py[DEBUG]: Running ['blkid', '-tTYPE=iso9660', '-odevice'] took 0.012 seconds
>2025-09-17 10:38:55,894 - subp.py[DEBUG]: Running command ['blkid', '-tLABEL=CIDATA', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
>2025-09-17 10:38:55,905 - performance.py[DEBUG]: Running ['blkid', '-tLABEL=CIDATA', '-odevice'] took 0.011 seconds
>2025-09-17 10:38:55,906 - subp.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
>2025-09-17 10:38:55,917 - performance.py[DEBUG]: Running ['blkid', '-tLABEL=cidata', '-odevice'] took 0.011 seconds
>2025-09-17 10:38:55,917 - subp.py[DEBUG]: Running command ['blkid', '-tLABEL_FATBOOT=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
>2025-09-17 10:38:55,928 - performance.py[DEBUG]: Running ['blkid', '-tLABEL_FATBOOT=cidata', '-odevice'] took 0.011 seconds
>2025-09-17 10:38:55,928 - DataSourceNoCloud.py[DEBUG]: Attempting to use data from /dev/sr0
>2025-09-17 10:38:55,929 - util.py[DEBUG]: Reading from /proc/mounts (quiet=False)
>2025-09-17 10:38:55,929 - util.py[DEBUG]: Reading 1358 bytes from /proc/mounts
>2025-09-17 10:38:55,929 - util.py[DEBUG]: Fetched {'udevfs': {'fstype': 'devtmpfs', 'mountpoint': '/dev', 'opts': 'rw,relatime,size=5120k,nr_inodes=494260,mode=755,inode64'}, 'runfs': {'fstype': 'tmpfs', 'mountpoint': '/run', 'opts': 'rw,relatime,mode=755,inode64'}, '/dev/mapper/alt-root': {'fstype': 'ext4', 'mountpoint': '/', 'opts': 'rw,relatime'}, 'proc': {'fstype': 'proc', 'mountpoint': '/proc', 'opts': 'rw,nosuid,noexec,relatime,gid=19'}, 'sysfs': {'fstype': 'sysfs', 'mountpoint': '/sys', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'securityfs': {'fstype': 'securityfs', 'mountpoint': '/sys/kernel/security', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'tmpfs': {'fstype': 'tmpfs', 'mountpoint': '/tmp/.private/root', 'opts': 'rw,relatime,inode64'}, 'devpts': {'fstype': 'devpts', 'mountpoint': '/dev/pts', 'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000'}, 'cgroup2': {'fstype': 'cgroup2', 'mountpoint': '/sys/fs/cgroup', 'opts': 'rw,nosuid,nodev,noexec,relatime,nsdelegate,memory_recursiveprot'}, 'pstore': {'fstype': 'pstore', 'mountpoint': '/sys/fs/pstore', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'bpf': {'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=5530'}, 'hugetlbfs': {'fstype': 'hugetlbfs', 'mountpoint': '/dev/hugepages', 'opts': 'rw,relatime,pagesize=2M'}, 'mqueue': {'fstype': 'mqueue', 'mountpoint': '/dev/mqueue', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'tracefs': {'fstype': 'tracefs', 'mountpoint': '/sys/kernel/tracing', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'fusectl': {'fstype': 'fusectl', 'mountpoint': '/sys/fs/fuse/connections', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'configfs': {'fstype': 'configfs', 'mountpoint': '/sys/kernel/config', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, '/dev/vda1': {'fstype': 'ext4', 'mountpoint': '/boot', 'opts': 'rw,nosuid,nodev,noexec,relatime'}} mounts from proc
>2025-09-17 10:38:55,930 - subp.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'auto', '/dev/sr0', '/run/cloud-init/tmp/tmps6e37gjr'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:55,943 - performance.py[DEBUG]: Running ['mount', '-o', 'ro', '-t', 'auto', '/dev/sr0', '/run/cloud-init/tmp/tmps6e37gjr'] took 0.013 seconds
>2025-09-17 10:38:55,943 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmps6e37gjr//user-data (quiet=False)
>2025-09-17 10:38:55,943 - util.py[DEBUG]: Reading 1179 bytes from /run/cloud-init/tmp/tmps6e37gjr//user-data
>2025-09-17 10:38:55,943 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmps6e37gjr//meta-data (quiet=False)
>2025-09-17 10:38:55,944 - util.py[DEBUG]: Reading 62 bytes from /run/cloud-init/tmp/tmps6e37gjr//meta-data
>2025-09-17 10:38:55,944 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmps6e37gjr//vendor-data (quiet=False)
>2025-09-17 10:38:55,944 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmps6e37gjr//network-config (quiet=False)
>2025-09-17 10:38:55,944 - util.py[DEBUG]: Reading 210 bytes from /run/cloud-init/tmp/tmps6e37gjr//network-config
>2025-09-17 10:38:55,944 - subp.py[DEBUG]: Running command ['umount', '/run/cloud-init/tmp/tmps6e37gjr'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:55,948 - util.py[DEBUG]: Attempting to load yaml from string of length 62 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,949 - util.py[DEBUG]: Attempting to load yaml from string of length 210 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,950 - DataSourceNoCloud.py[DEBUG]: Using data from /dev/sr0
>2025-09-17 10:38:55,951 - util.py[DEBUG]: Writing to /run/cloud-init/cloud-id-nocloud - wb: [644] 8 bytes
>2025-09-17 10:38:55,952 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/cloud-id' => '/run/cloud-init/cloud-id-nocloud'
>2025-09-17 10:38:55,952 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmpkm9f50ro) - w: [600] 8288 bytes/chars
>2025-09-17 10:38:55,953 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data.json (via temporary file /run/cloud-init/tmpqrssuu2q) - w: [644] 1569 bytes/chars
>2025-09-17 10:38:55,953 - performance.py[DEBUG]: Getting metadata took 0.088 seconds
>2025-09-17 10:38:55,953 - handlers.py[DEBUG]: finish: init-local/search-NoCloud: SUCCESS: found local data from DataSourceNoCloud
>2025-09-17 10:38:55,953 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
>2025-09-17 10:38:55,953 - stages.py[INFO]: Loaded datasource DataSourceNoCloud - DataSourceNoCloud [seed=/dev/sr0][dsmode=local]
>2025-09-17 10:38:55,953 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:55,953 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:55,954 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,958 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:55,958 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:55,958 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,959 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:55,959 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:55,959 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,959 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:55,959 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:55,960 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,960 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:55,960 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:55,960 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,963 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:55,963 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,964 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:55,964 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
>2025-09-17 10:38:55,964 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/nocloud'
>2025-09-17 10:38:55,965 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/nocloud/datasource (quiet=False)
>2025-09-17 10:38:55,965 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/datasource - wb: [644] 67 bytes
>2025-09-17 10:38:55,965 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 67 bytes
>2025-09-17 10:38:55,966 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
>2025-09-17 10:38:55,966 - stages.py[DEBUG]: previous iid found to be NO_PREVIOUS_INSTANCE_ID
>2025-09-17 10:38:55,966 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 8 bytes
>2025-09-17 10:38:55,966 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 8 bytes
>2025-09-17 10:38:55,966 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 24 bytes
>2025-09-17 10:38:55,967 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 6140 bytes
>2025-09-17 10:38:55,967 - main.py[DEBUG]: [local] init will now be targeting instance id: nocloud. new=True
>2025-09-17 10:38:55,967 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:55,967 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:55,967 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,972 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:55,972 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:55,972 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,972 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:55,972 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:55,972 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,973 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:55,973 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:55,973 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,973 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:55,973 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:55,973 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,976 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:55,977 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:55,977 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:55,977 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.altlinux.Distro'>
>2025-09-17 10:38:55,978 - cc_set_hostname.py[DEBUG]: Setting the hostname to test-cinita-01.a02.rt (test-cinita-01)
>2025-09-17 10:38:55,978 - subp.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'test-cinita-01'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,045 - performance.py[DEBUG]: Running ['hostnamectl', 'set-hostname', 'test-cinita-01'] took 0.067 seconds
>2025-09-17 10:38:56,046 - distros[DEBUG]: Non-persistently setting the system hostname to test-cinita-01
>2025-09-17 10:38:56,046 - subp.py[DEBUG]: Running command ['hostname', 'test-cinita-01'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,049 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/set-hostname (via temporary file /var/lib/cloud/data/tmpci9a_he2) - w: [644] 68 bytes/chars
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/eth0/address
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/lo/address
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/eth0/address
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
>2025-09-17 10:38:56,051 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/lo/address
>2025-09-17 10:38:56,052 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/instance/network-config.json (via temporary file /var/lib/cloud/instance/tmpqnj5ktpt) - w: [600] 285 bytes/chars
>2025-09-17 10:38:56,052 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/network-config.json' => '/var/lib/cloud/instance/network-config.json'
>2025-09-17 10:38:56,052 - util.py[DEBUG]: Reading from /usr/lib/python3/site-packages/cloudinit/config/schemas/schema-network-config-v1.json (quiet=False)
>2025-09-17 10:38:56,053 - util.py[DEBUG]: Reading 21473 bytes from /usr/lib/python3/site-packages/cloudinit/config/schemas/schema-network-config-v1.json
>2025-09-17 10:38:56,053 - schema.py[DEBUG]: Ignoring schema validation. jsonschema is not present
>2025-09-17 10:38:56,053 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
>2025-09-17 10:38:56,053 - util.py[DEBUG]: Reading 7 bytes from /sys/class/net/eth0/device/device
>2025-09-17 10:38:56,053 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False)
>2025-09-17 10:38:56,053 - util.py[DEBUG]: Reading 2 bytes from /sys/class/net/eth0/addr_assign_type
>2025-09-17 10:38:56,053 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading 25 bytes from /sys/class/net/eth0/uevent
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/eth0/address
>2025-09-17 10:38:56,054 - net[DEBUG]: ovs-vsctl not in PATH; not detecting Open vSwitch interfaces
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading 7 bytes from /sys/class/net/eth0/device/device
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading 2 bytes from /sys/class/net/lo/addr_assign_type
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading 23 bytes from /sys/class/net/lo/uevent
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/lo/address
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/eth0/type (quiet=False)
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading 2 bytes from /sys/class/net/eth0/type
>2025-09-17 10:38:56,054 - util.py[DEBUG]: Reading from /sys/class/net/lo/type (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 4 bytes from /sys/class/net/lo/type
>2025-09-17 10:38:56,055 - networking.py[DEBUG]: net: all expected physical devices present
>2025-09-17 10:38:56,055 - stages.py[DEBUG]: applying net config names for {'config': [{'mac_address': '52:54:00:00:14:5b', 'name': 'eth0', 'subnets': [{'dns_nameservers': ['10.255.48.19', '10.255.48.20'], 'gateway': '10.255.48.1', 'type': 'dhcp'}], 'type': 'physical'}], 'version': 1}
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 7 bytes from /sys/class/net/eth0/device/device
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 2 bytes from /sys/class/net/eth0/addr_assign_type
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 25 bytes from /sys/class/net/eth0/uevent
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/eth0/address
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 7 bytes from /sys/class/net/eth0/device/device
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 2 bytes from /sys/class/net/lo/addr_assign_type
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 23 bytes from /sys/class/net/lo/uevent
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading 18 bytes from /sys/class/net/lo/address
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
>2025-09-17 10:38:56,055 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False)
>2025-09-17 10:38:56,056 - util.py[DEBUG]: Reading 5 bytes from /sys/class/net/eth0/operstate
>2025-09-17 10:38:56,056 - util.py[DEBUG]: Reading from /sys/class/net/lo/operstate (quiet=False)
>2025-09-17 10:38:56,056 - util.py[DEBUG]: Reading 8 bytes from /sys/class/net/lo/operstate
>2025-09-17 10:38:56,056 - subp.py[DEBUG]: Running command ['ip', '-6', 'addr', 'show', 'permanent', 'scope', 'global'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,062 - subp.py[DEBUG]: Running command ['ip', '-4', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,065 - net[DEBUG]: Detected interfaces {'eth0': {'downable': True, 'device_id': '0x0001', 'driver': 'virtio_net', 'mac': '52:54:00:00:14:5b', 'name': 'eth0', 'up': False}, 'lo': {'downable': False, 'device_id': None, 'driver': None, 'mac': '00:00:00:00:00:00', 'name': 'lo', 'up': True}}
>2025-09-17 10:38:56,066 - net[DEBUG]: no work necessary for renaming of [['52:54:00:00:14:5b', 'eth0', 'virtio_net', '0x0001']]
>2025-09-17 10:38:56,066 - stages.py[INFO]: Applying network configuration from ds bringup=False: {'config': [{'mac_address': '52:54:00:00:14:5b', 'name': 'eth0', 'subnets': [{'dns_nameservers': ['10.255.48.19', '10.255.48.20'], 'gateway': '10.255.48.1', 'type': 'dhcp'}], 'type': 'physical'}], 'version': 1}
>2025-09-17 10:38:56,066 - util.py[DEBUG]: Writing to /run/cloud-init/sem/apply_network_config.once - wb: [644] 25 bytes
>2025-09-17 10:38:56,067 - subp.py[DEBUG]: Running command ['systemctl', 'is-enabled', 'NetworkManager.service'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,075 - stages.py[ERROR]: Unable to render networking. Network config is likely broken: No available network renderers found. Searched through list: ['eni', 'sysconfig', 'netplan', 'network-manager', 'freebsd', 'etcnet', 'netbsd', 'openbsd', 'networkd']
>2025-09-17 10:38:56,082 - main.py[DEBUG]: Network connectivity determined unnecessary for cloud-init's network stage. Reason: user data: cloud-config does not contain network requiring elements, vendor data: no configuration found, vendor data2: no configuration found
>2025-09-17 10:38:56,082 - util.py[DEBUG]: Writing to /run/cloud-init/.skip-network - wb: [644] 0 bytes
>2025-09-17 10:38:56,082 - main.py[DEBUG]: [local] DataSourceNoCloud [seed=/dev/sr0][dsmode=local] is in local mode, will apply init modules now.
>2025-09-17 10:38:56,083 - handlers.py[DEBUG]: start: init-local/setup-datasource: setting up datasource
>2025-09-17 10:38:56,083 - handlers.py[DEBUG]: finish: init-local/setup-datasource: SUCCESS: setting up datasource
>2025-09-17 10:38:56,083 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt - wb: [600] 1179 bytes
>2025-09-17 10:38:56,083 - util.py[DEBUG]: Attempting to load yaml from string of length 1179 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,090 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt.i - wb: [600] 1484 bytes
>2025-09-17 10:38:56,090 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data.txt - wb: [600] 0 bytes
>2025-09-17 10:38:56,091 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data.txt.i - wb: [600] 308 bytes
>2025-09-17 10:38:56,091 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data2.txt - wb: [600] 0 bytes
>2025-09-17 10:38:56,092 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data2.txt.i - wb: [600] 308 bytes
>2025-09-17 10:38:56,093 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False)
>2025-09-17 10:38:56,093 - util.py[DEBUG]: Reading 68 bytes from /var/lib/cloud/data/set-hostname
>2025-09-17 10:38:56,093 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set_hostname
>2025-09-17 10:38:56,093 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/consume_data - wb: [644] 25 bytes
>2025-09-17 10:38:56,093 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/consume_data'>)
>2025-09-17 10:38:56,093 - handlers.py[DEBUG]: start: init-local/consume-user-data: reading and applying user-data
>2025-09-17 10:38:56,094 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
>2025-09-17 10:38:56,094 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
>2025-09-17 10:38:56,094 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-boot'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']]
>2025-09-17 10:38:56,094 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-instance'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']]
>2025-09-17 10:38:56,094 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript-per-once'} from ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']]
>2025-09-17 10:38:56,094 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
>2025-09-17 10:38:56,094 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']] (__begin__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']] (__begin__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']] (__begin__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance
>2025-09-17 10:38:56,094 - handlers[DEBUG]: {'MIME-Version': '1.0', 'Content-Type': 'text/cloud-config', 'Content-Disposition': 'attachment; filename="part-001"'}
>2025-09-17 10:38:56,094 - handlers[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance
>2025-09-17 10:38:56,094 - util.py[DEBUG]: Attempting to load yaml from string of length 1179 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,101 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])]
>2025-09-17 10:38:56,101 - handlers[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
>2025-09-17 10:38:56,104 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/cloud-config.txt - wb: [600] 1305 bytes
>2025-09-17 10:38:56,104 - handlers[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,104 - handlers[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-boot']] (__end__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,104 - handlers[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-instance']] (__end__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,104 - handlers[DEBUG]: Calling handler ShellScriptByFreqPartHandler: [['text/x-shellscript-per-once']] (__end__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,104 - handlers[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
>2025-09-17 10:38:56,104 - handlers[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance
>2025-09-17 10:38:56,104 - handlers.py[DEBUG]: finish: init-local/consume-user-data: SUCCESS: reading and applying user-data
>2025-09-17 10:38:56,104 - handlers.py[DEBUG]: start: init-local/consume-vendor-data: reading and applying vendor-data
>2025-09-17 10:38:56,104 - stages.py[DEBUG]: no vendordata from datasource
>2025-09-17 10:38:56,104 - handlers.py[DEBUG]: finish: init-local/consume-vendor-data: SUCCESS: reading and applying vendor-data
>2025-09-17 10:38:56,104 - handlers.py[DEBUG]: start: init-local/consume-vendor-data2: reading and applying vendor-data2
>2025-09-17 10:38:56,104 - stages.py[DEBUG]: no vendordata2 from datasource
>2025-09-17 10:38:56,104 - handlers.py[DEBUG]: finish: init-local/consume-vendor-data2: SUCCESS: reading and applying vendor-data2
>2025-09-17 10:38:56,105 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:56,105 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:56,105 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,109 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:56,109 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:56,109 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,110 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:56,110 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:56,110 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,111 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:56,111 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:56,111 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,111 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:56,111 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:56,111 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,114 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:56,114 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,114 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:56,115 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:56,115 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:56,115 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,121 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/combined-cloud-config.json (via temporary file /run/cloud-init/tmp5pxbk5s4) - w: [600] 5658 bytes/chars
>2025-09-17 10:38:56,121 - util.py[DEBUG]: Reading from /run/cloud-init/instance-data-sensitive.json (quiet=False)
>2025-09-17 10:38:56,121 - util.py[DEBUG]: Reading 8288 bytes from /run/cloud-init/instance-data-sensitive.json
>2025-09-17 10:38:56,121 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmp1s7z0mw1) - w: [600] 9119 bytes/chars
>2025-09-17 10:38:56,121 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:56,121 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:56,126 - util.py[DEBUG]: Reading from /usr/lib/python3/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json (quiet=False)
>2025-09-17 10:38:56,127 - util.py[DEBUG]: Reading 149917 bytes from /usr/lib/python3/site-packages/cloudinit/config/schemas/schema-cloud-config-v1.json
>2025-09-17 10:38:56,128 - schema.py[DEBUG]: Ignoring schema validation. jsonschema is not present
>2025-09-17 10:38:56,129 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:56,129 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:56,129 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,136 - handlers.py[DEBUG]: start: init-local/activate-datasource: activating datasource
>2025-09-17 10:38:56,136 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 8913 bytes
>2025-09-17 10:38:56,137 - handlers.py[DEBUG]: finish: init-local/activate-datasource: SUCCESS: activating datasource
>2025-09-17 10:38:56,137 - main.py[DEBUG]: no di_report found in config.
>2025-09-17 10:38:56,148 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.altlinux.Distro'>
>2025-09-17 10:38:56,149 - modules.py[INFO]: Skipping modules 'rh_subscription,write-files,rsyslog' because no applicable config is provided.
>2025-09-17 10:38:56,149 - modules.py[DEBUG]: Running module growpart (<module 'cloudinit.config.cc_growpart' from '/usr/lib/python3/site-packages/cloudinit/config/cc_growpart.py'>) with frequency always
>2025-09-17 10:38:56,149 - handlers.py[DEBUG]: start: init-local/config-growpart: running config-growpart with frequency always
>2025-09-17 10:38:56,150 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x7f0497f4a5b0>)
>2025-09-17 10:38:56,150 - subp.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,157 - cc_growpart.py[DEBUG]: growpart found fs=None
>2025-09-17 10:38:56,157 - util.py[DEBUG]: Reading from /sys/class/block/vda2/partition (quiet=False)
>2025-09-17 10:38:56,157 - util.py[DEBUG]: Reading 2 bytes from /sys/class/block/vda2/partition
>2025-09-17 10:38:56,158 - util.py[DEBUG]: Reading from /sys/devices/pci0000:00/0000:00:06.0/virtio2/block/vda/dev (quiet=False)
>2025-09-17 10:38:56,158 - util.py[DEBUG]: Reading 6 bytes from /sys/devices/pci0000:00/0000:00:06.0/virtio2/block/vda/dev
>2025-09-17 10:38:56,158 - util.py[DEBUG]: Reading from /proc/2218/mountinfo (quiet=False)
>2025-09-17 10:38:56,158 - util.py[DEBUG]: Reading 1829 bytes from /proc/2218/mountinfo
>2025-09-17 10:38:56,158 - util.py[DEBUG]: Reading from /proc/2218/mountinfo (quiet=False)
>2025-09-17 10:38:56,158 - util.py[DEBUG]: Reading 1829 bytes from /proc/2218/mountinfo
>2025-09-17 10:38:56,158 - subp.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/vda', '2'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,198 - performance.py[DEBUG]: Running ['growpart', '--dry-run', '/dev/vda', '2'] took 0.040 seconds
>2025-09-17 10:38:56,198 - subp.py[DEBUG]: Running command ['growpart', '/dev/vda', '2'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,638 - performance.py[DEBUG]: Running ['growpart', '/dev/vda', '2'] took 0.439 seconds
>2025-09-17 10:38:56,638 - performance.py[DEBUG]: Resizing devices took 0.481 seconds
>2025-09-17 10:38:56,638 - cc_growpart.py[INFO]: '/dev/vda2' resized: changed (/dev/vda2) from 6978273280 to 53150203392
>2025-09-17 10:38:56,639 - handlers.py[DEBUG]: finish: init-local/config-growpart: SUCCESS: config-growpart ran successfully and took 0.489 seconds
>2025-09-17 10:38:56,639 - modules.py[DEBUG]: Running module resizefs (<module 'cloudinit.config.cc_resizefs' from '/usr/lib/python3/site-packages/cloudinit/config/cc_resizefs.py'>) with frequency always
>2025-09-17 10:38:56,639 - handlers.py[DEBUG]: start: init-local/config-resizefs: running config-resizefs with frequency always
>2025-09-17 10:38:56,639 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x7f0497f4abb0>)
>2025-09-17 10:38:56,639 - util.py[DEBUG]: Reading from /proc/2218/mountinfo (quiet=False)
>2025-09-17 10:38:56,639 - util.py[DEBUG]: Reading 1829 bytes from /proc/2218/mountinfo
>2025-09-17 10:38:56,639 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/mapper/alt-root mnt_point=/ path=/
>2025-09-17 10:38:56,639 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/mapper/alt-root
>2025-09-17 10:38:56,640 - subp.py[DEBUG]: Running command ('resize2fs', '/dev/mapper/alt-root') with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,643 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True)
>2025-09-17 10:38:56,644 - handlers.py[DEBUG]: finish: init-local/config-resizefs: SUCCESS: config-resizefs ran successfully and took 0.005 seconds
>2025-09-17 10:38:56,644 - modules.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python3/site-packages/cloudinit/config/cc_set_hostname.py'>) with frequency once-per-instance
>2025-09-17 10:38:56,644 - handlers.py[DEBUG]: start: init-local/config-set_hostname: running config-set_hostname with frequency once-per-instance
>2025-09-17 10:38:56,644 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_set_hostname - wb: [644] 24 bytes
>2025-09-17 10:38:56,645 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_set_hostname'>)
>2025-09-17 10:38:56,645 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False)
>2025-09-17 10:38:56,645 - util.py[DEBUG]: Reading 68 bytes from /var/lib/cloud/data/set-hostname
>2025-09-17 10:38:56,645 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set_hostname
>2025-09-17 10:38:56,645 - handlers.py[DEBUG]: finish: init-local/config-set_hostname: SUCCESS: config-set_hostname ran successfully and took 0.001 seconds
>2025-09-17 10:38:56,645 - modules.py[DEBUG]: Running module update_hostname (<module 'cloudinit.config.cc_update_hostname' from '/usr/lib/python3/site-packages/cloudinit/config/cc_update_hostname.py'>) with frequency always
>2025-09-17 10:38:56,646 - handlers.py[DEBUG]: start: init-local/config-update_hostname: running config-update_hostname with frequency always
>2025-09-17 10:38:56,646 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x7f0497f4ae80>)
>2025-09-17 10:38:56,646 - cc_update_hostname.py[DEBUG]: Updating hostname to test-cinita-01.a02.rt (test-cinita-01)
>2025-09-17 10:38:56,646 - subp.py[DEBUG]: Running command ['hostname'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,650 - distros[DEBUG]: Attempting to update hostname to test-cinita-01.a02.rt in 1 files
>2025-09-17 10:38:56,650 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-hostname - wb: [644] 21 bytes
>2025-09-17 10:38:56,651 - handlers.py[DEBUG]: finish: init-local/config-update_hostname: SUCCESS: config-update_hostname ran successfully and took 0.005 seconds
>2025-09-17 10:38:56,651 - modules.py[DEBUG]: Running module update_etc_hosts (<module 'cloudinit.config.cc_update_etc_hosts' from '/usr/lib/python3/site-packages/cloudinit/config/cc_update_etc_hosts.py'>) with frequency always
>2025-09-17 10:38:56,651 - handlers.py[DEBUG]: start: init-local/config-update_etc_hosts: running config-update_etc_hosts with frequency always
>2025-09-17 10:38:56,652 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x7f0497f2ca90>)
>2025-09-17 10:38:56,652 - util.py[DEBUG]: Reading from /etc/cloud/templates/hosts.altlinux.tmpl (quiet=False)
>2025-09-17 10:38:56,652 - util.py[DEBUG]: Reading 960 bytes from /etc/cloud/templates/hosts.altlinux.tmpl
>2025-09-17 10:38:56,652 - templater.py[DEBUG]: Rendering content of '/etc/cloud/templates/hosts.altlinux.tmpl' using renderer jinja
>2025-09-17 10:38:56,658 - util.py[DEBUG]: Writing to /etc/hosts - wb: [644] 766 bytes
>2025-09-17 10:38:56,659 - handlers.py[DEBUG]: finish: init-local/config-update_etc_hosts: SUCCESS: config-update_etc_hosts ran successfully and took 0.008 seconds
>2025-09-17 10:38:56,659 - modules.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/lib/python3/site-packages/cloudinit/config/cc_users_groups.py'>) with frequency once-per-instance
>2025-09-17 10:38:56,660 - handlers.py[DEBUG]: start: init-local/config-users-groups: running config-users-groups with frequency once-per-instance
>2025-09-17 10:38:56,660 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_users_groups - wb: [644] 24 bytes
>2025-09-17 10:38:56,660 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_users_groups'>)
>2025-09-17 10:38:56,668 - util.py[DEBUG]: Reading from /etc/os-release (quiet=True)
>2025-09-17 10:38:56,668 - util.py[DEBUG]: Reading 287 bytes from /etc/os-release
>2025-09-17 10:38:56,668 - util.py[DEBUG]: Reading from /etc/system-image/channel.ini (quiet=True)
>2025-09-17 10:38:56,668 - util.py[DEBUG]: Reading 0 bytes from /etc/system-image/channel.ini
>2025-09-17 10:38:56,669 - distros[DEBUG]: Adding user user
>2025-09-17 10:38:56,669 - subp.py[DEBUG]: Running command ['useradd', 'user', '--expiredate', '2038-01-01', '--groups', 'wheel', '--shell', '/bin/bash', '-m'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,707 - performance.py[DEBUG]: Running ['useradd', 'user', '--expiredate', '2038-01-01', '--groups', 'wheel', '--shell', '/bin/bash', '-m'] took 0.038 seconds
>2025-09-17 10:38:56,708 - subp.py[DEBUG]: Running command chpasswd for user with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,717 - subp.py[DEBUG]: Running command ['passwd', '-u', 'user'] with allowed return codes [0, 3] (shell=False, capture=True)
>2025-09-17 10:38:56,733 - performance.py[DEBUG]: Running ['passwd', '-u', 'user'] took 0.015 seconds
>2025-09-17 10:38:56,733 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False)
>2025-09-17 10:38:56,733 - util.py[DEBUG]: Reading 5475 bytes from /etc/sudoers
>2025-09-17 10:38:56,735 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - wb: [440] 111 bytes
>2025-09-17 10:38:56,735 - util.py[DEBUG]: Reading from /etc/openssh/sshd_config (quiet=False)
>2025-09-17 10:38:56,735 - util.py[DEBUG]: Reading 4242 bytes from /etc/openssh/sshd_config
>2025-09-17 10:38:56,736 - util.py[DEBUG]: Reading from /home/user/.ssh/authorized_keys (quiet=False)
>2025-09-17 10:38:56,736 - util.py[DEBUG]: Reading 75 bytes from /home/user/.ssh/authorized_keys
>2025-09-17 10:38:56,736 - util.py[DEBUG]: Writing to /home/user/.ssh/authorized_keys - wb: [600] 75 bytes
>2025-09-17 10:38:56,736 - handlers.py[DEBUG]: finish: init-local/config-users-groups: SUCCESS: config-users-groups ran successfully and took 0.077 seconds
>2025-09-17 10:38:56,736 - modules.py[DEBUG]: Running module ssh (<module 'cloudinit.config.cc_ssh' from '/usr/lib/python3/site-packages/cloudinit/config/cc_ssh.py'>) with frequency once-per-instance
>2025-09-17 10:38:56,737 - handlers.py[DEBUG]: start: init-local/config-ssh: running config-ssh with frequency once-per-instance
>2025-09-17 10:38:56,737 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh - wb: [644] 25 bytes
>2025-09-17 10:38:56,737 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh'>)
>2025-09-17 10:38:56,738 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_ecdsa_key
>2025-09-17 10:38:56,738 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_rsa_key
>2025-09-17 10:38:56,738 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_ed25519_key.pub
>2025-09-17 10:38:56,738 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_ecdsa_key.pub
>2025-09-17 10:38:56,738 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_dsa_key.pub
>2025-09-17 10:38:56,738 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_ed25519_key
>2025-09-17 10:38:56,739 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_rsa_key.pub
>2025-09-17 10:38:56,739 - util.py[DEBUG]: Attempting to remove /etc/openssh/ssh_host_dsa_key
>2025-09-17 10:38:56,739 - util.py[DEBUG]: Reading from /proc/sys/crypto/fips_enabled (quiet=False)
>2025-09-17 10:38:56,739 - util.py[DEBUG]: Reading from /etc/openssh/sshd_config (quiet=False)
>2025-09-17 10:38:56,739 - util.py[DEBUG]: Reading 4242 bytes from /etc/openssh/sshd_config
>2025-09-17 10:38:56,740 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False)
>2025-09-17 10:38:56,740 - util.py[DEBUG]: Reading 75 bytes from /root/.ssh/authorized_keys
>2025-09-17 10:38:56,740 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 75 bytes
>2025-09-17 10:38:56,741 - handlers.py[DEBUG]: finish: init-local/config-ssh: SUCCESS: config-ssh ran successfully and took 0.004 seconds
>2025-09-17 10:38:56,741 - modules.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/lib/python3/site-packages/cloudinit/config/cc_bootcmd.py'>) with frequency always
>2025-09-17 10:38:56,741 - handlers.py[DEBUG]: start: init-local/config-bootcmd: running config-bootcmd with frequency always
>2025-09-17 10:38:56,741 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x7f0497f4aca0>)
>2025-09-17 10:38:56,741 - util.py[DEBUG]: Shellified 2 commands.
>2025-09-17 10:38:56,741 - subp.py[DEBUG]: Running command ['/bin/sh', '/run/cloud-init/tmp/tmpe0co4q0j.sh'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:38:56,796 - performance.py[DEBUG]: Running ['/bin/sh', '/run/cloud-init/tmp/tmpe0co4q0j.sh'] took 0.054 seconds
>2025-09-17 10:38:56,796 - handlers.py[DEBUG]: finish: init-local/config-bootcmd: SUCCESS: config-bootcmd ran successfully and took 0.055 seconds
>2025-09-17 10:38:56,797 - main.py[DEBUG]: Ran 8 modules with 0 failures
>2025-09-17 10:38:56,797 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:38:56,797 - util.py[DEBUG]: Reading 10 bytes from /proc/uptime
>2025-09-17 10:38:56,797 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpbvfdh2o7) - w: [644] 1568 bytes/chars
>2025-09-17 10:38:56,798 - performance.py[DEBUG]: cloud-init stage: 'init-local' took 0.984 seconds
>2025-09-17 10:38:56,798 - handlers.py[DEBUG]: finish: init-local: SUCCESS: searching for local datasources
>2025-09-17 10:38:56,798 - socket.py[INFO]: Sending sd_notify(STATUS=Waiting on external services to complete before starting the network stage.)
>2025-09-17 10:38:56,892 - performance.py[DEBUG]: Waiting to start stage network took 0.094 seconds
>2025-09-17 10:38:56,892 - socket.py[INFO]: Sending sd_notify(STATUS=Running (network stage))
>2025-09-17 10:38:56,894 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:38:56,894 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:38:56,894 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:38:56,894 - handlers.py[DEBUG]: start: init-network: searching for network datasources
>2025-09-17 10:38:56,894 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:56,894 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:56,895 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,900 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:56,900 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:56,900 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,900 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:56,900 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:56,900 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,901 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:56,901 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:56,901 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,901 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:56,901 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:56,902 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,905 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:56,905 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,905 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:56,905 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:56,905 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:56,905 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,911 - util.py[DEBUG]: Reading from /var/lib/cloud/data/status.json (quiet=False)
>2025-09-17 10:38:56,911 - util.py[DEBUG]: Reading 1568 bytes from /var/lib/cloud/data/status.json
>2025-09-17 10:38:56,911 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:38:56,911 - util.py[DEBUG]: Reading 10 bytes from /proc/uptime
>2025-09-17 10:38:56,911 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpqin3alf0) - w: [644] 1570 bytes/chars
>2025-09-17 10:38:56,911 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/status.json' => '../../var/lib/cloud/data/status.json'
>2025-09-17 10:38:56,912 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:38:56,912 - util.py[DEBUG]: Reading 10 bytes from /proc/uptime
>2025-09-17 10:38:56,912 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:56,912 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:56,912 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,916 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:56,916 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:56,917 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,917 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:56,917 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:56,917 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,918 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:56,918 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:56,918 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,918 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:56,918 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:56,918 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,921 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:56,921 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,921 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:56,922 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:56,922 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:56,922 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:56,927 - log_util.py[DEBUG]: Cloud-init v. 25.1.4 running 'init' at Wed, 17 Sep 2025 10:38:56 +0000. Up 8.94 seconds.
>2025-09-17 10:38:56,927 - main.py[INFO]: PID [1] started cloud-init 'init'.
>2025-09-17 10:38:56,927 - main.py[DEBUG]: No kernel command line url found.
>2025-09-17 10:38:56,929 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [640] 0 bytes
>2025-09-17 10:38:56,929 - util.py[DEBUG]: Reading from /var/lib/cloud/data/python-version (quiet=False)
>2025-09-17 10:38:56,929 - util.py[DEBUG]: Reading 3 bytes from /var/lib/cloud/data/python-version
>2025-09-17 10:38:56,930 - subp.py[DEBUG]: Running command ['ip', '--json', 'addr'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,937 - subp.py[DEBUG]: Running command ['ip', '-o', 'route', 'list'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:38:56,940 - subp.py[DEBUG]: Running command ['ip', '--oneline', '-6', 'route', 'list', 'table', 'all'] with allowed return codes [0, 1] (shell=False, capture=True)
>2025-09-17 10:38:56,944 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust]
>2025-09-17 10:38:56,945 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
>2025-09-17 10:38:56,945 - util.py[DEBUG]: Reading 8913 bytes from /var/lib/cloud/instance/obj.pkl
>2025-09-17 10:38:56,946 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
>2025-09-17 10:38:56,946 - util.py[DEBUG]: Reading 8 bytes from /run/cloud-init/.instance-id
>2025-09-17 10:38:56,946 - stages.py[DEBUG]: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=local]
>2025-09-17 10:38:56,946 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=local]
>2025-09-17 10:38:56,947 - main.py[DEBUG]: [net] Exiting. datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=local] in local mode
>2025-09-17 10:38:56,947 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:38:56,947 - util.py[DEBUG]: Reading 10 bytes from /proc/uptime
>2025-09-17 10:38:56,949 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpozgc46ca) - w: [644] 1568 bytes/chars
>2025-09-17 10:38:56,950 - performance.py[DEBUG]: cloud-init stage: 'init-network' took 0.055 seconds
>2025-09-17 10:38:56,950 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources
>2025-09-17 10:38:56,950 - socket.py[INFO]: Sending sd_notify(STATUS=Waiting on external services to complete before starting the config stage.)
>2025-09-17 10:38:56,984 - performance.py[DEBUG]: Waiting to start stage config took 0.035 seconds
>2025-09-17 10:38:56,985 - socket.py[INFO]: Sending sd_notify(STATUS=Running (config stage))
>2025-09-17 10:38:56,985 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:38:56,986 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:38:56,986 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:38:56,986 - handlers.py[DEBUG]: start: modules-config: running modules for config
>2025-09-17 10:38:56,986 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:56,986 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:56,986 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,004 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:57,004 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:57,005 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,006 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:57,006 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:57,006 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,011 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:57,012 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:57,012 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,012 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:57,012 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:57,012 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,025 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:57,026 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,026 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:57,027 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:57,027 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:57,027 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,037 - util.py[DEBUG]: Reading from /var/lib/cloud/data/status.json (quiet=False)
>2025-09-17 10:38:57,037 - util.py[DEBUG]: Reading 1568 bytes from /var/lib/cloud/data/status.json
>2025-09-17 10:38:57,037 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:38:57,037 - util.py[DEBUG]: Reading 10 bytes from /proc/uptime
>2025-09-17 10:38:57,038 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpx93gscxw) - w: [644] 1580 bytes/chars
>2025-09-17 10:38:57,038 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/status.json' => '../../var/lib/cloud/data/status.json'
>2025-09-17 10:38:57,040 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:38:57,040 - util.py[DEBUG]: Reading 10 bytes from /proc/uptime
>2025-09-17 10:38:57,041 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:57,041 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:57,041 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,049 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:57,050 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:57,050 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,050 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:57,050 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:57,051 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,052 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:57,052 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:57,052 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,052 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:57,052 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:57,052 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,059 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:57,059 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,059 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:57,059 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:57,059 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:57,059 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,065 - handlers.py[DEBUG]: start: modules-config/check-cache: attempting to read from cache [trust]
>2025-09-17 10:38:57,065 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
>2025-09-17 10:38:57,065 - util.py[DEBUG]: Reading 8913 bytes from /var/lib/cloud/instance/obj.pkl
>2025-09-17 10:38:57,066 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
>2025-09-17 10:38:57,066 - util.py[DEBUG]: Reading 8 bytes from /run/cloud-init/.instance-id
>2025-09-17 10:38:57,066 - stages.py[DEBUG]: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=local]
>2025-09-17 10:38:57,066 - handlers.py[DEBUG]: finish: modules-config/check-cache: SUCCESS: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=local]
>2025-09-17 10:38:57,066 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:38:57,066 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:38:57,066 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,072 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:38:57,072 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:38:57,072 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,072 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:38:57,072 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:38:57,073 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,073 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:38:57,073 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:38:57,073 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,074 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:38:57,074 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:38:57,074 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,078 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:38:57,078 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,078 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:38:57,078 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:57,078 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:57,078 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,086 - log_util.py[DEBUG]: Cloud-init v. 25.1.4 running 'modules:config' at Wed, 17 Sep 2025 10:38:57 +0000. Up 9.07 seconds.
>2025-09-17 10:38:57,086 - main.py[INFO]: PID [1] started cloud-init 'modules:config'.
>2025-09-17 10:38:57,086 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:38:57,086 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:38:57,086 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:38:57,105 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.altlinux.Distro'>
>2025-09-17 10:38:57,107 - modules.py[INFO]: Skipping modules 'yum-add-repo,puppet,chef,mcollective,disable-ec2-metadata' because no applicable config is provided.
>2025-09-17 10:38:57,107 - modules.py[DEBUG]: Running module mounts (<module 'cloudinit.config.cc_mounts' from '/usr/lib/python3/site-packages/cloudinit/config/cc_mounts.py'>) with frequency once-per-instance
>2025-09-17 10:38:57,108 - handlers.py[DEBUG]: start: modules-config/config-mounts: running config-mounts with frequency once-per-instance
>2025-09-17 10:38:57,109 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_mounts - wb: [644] 25 bytes
>2025-09-17 10:38:57,109 - helpers.py[DEBUG]: Running config-mounts using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_mounts'>)
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: mounts configuration is []
>2025-09-17 10:38:57,109 - util.py[DEBUG]: Reading from /etc/fstab (quiet=False)
>2025-09-17 10:38:57,109 - util.py[DEBUG]: Reading 416 bytes from /etc/fstab
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: changed ephemeral0 => None
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount ephemeral0
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: Attempting to determine the real name of swap
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: changed swap => None
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount swap
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: no need to setup swap
>2025-09-17 10:38:57,109 - cc_mounts.py[DEBUG]: No modifications to fstab needed
>2025-09-17 10:38:57,110 - handlers.py[DEBUG]: finish: modules-config/config-mounts: SUCCESS: config-mounts ran successfully and took 0.001 seconds
>2025-09-17 10:38:57,110 - modules.py[DEBUG]: Running module locale (<module 'cloudinit.config.cc_locale' from '/usr/lib/python3/site-packages/cloudinit/config/cc_locale.py'>) with frequency once-per-instance
>2025-09-17 10:38:57,110 - handlers.py[DEBUG]: start: modules-config/config-locale: running config-locale with frequency once-per-instance
>2025-09-17 10:38:57,110 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_locale - wb: [644] 24 bytes
>2025-09-17 10:38:57,111 - helpers.py[DEBUG]: Running config-locale using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_locale'>)
>2025-09-17 10:38:57,111 - cc_locale.py[DEBUG]: Setting locale to en_US.UTF-8
>2025-09-17 10:38:57,111 - util.py[DEBUG]: Reading from /etc/locale.conf (quiet=False)
>2025-09-17 10:38:57,111 - util.py[DEBUG]: Reading 17 bytes from /etc/locale.conf
>2025-09-17 10:38:57,111 - util.py[DEBUG]: Writing to /etc/locale.conf - wb: [644] 17 bytes
>2025-09-17 10:38:57,112 - handlers.py[DEBUG]: finish: modules-config/config-locale: SUCCESS: config-locale ran successfully and took 0.001 seconds
>2025-09-17 10:38:57,112 - modules.py[DEBUG]: Running module set-passwords (<module 'cloudinit.config.cc_set_passwords' from '/usr/lib/python3/site-packages/cloudinit/config/cc_set_passwords.py'>) with frequency once-per-instance
>2025-09-17 10:38:57,112 - handlers.py[DEBUG]: start: modules-config/config-set-passwords: running config-set-passwords with frequency once-per-instance
>2025-09-17 10:38:57,112 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_set_passwords - wb: [644] 25 bytes
>2025-09-17 10:38:57,112 - helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_set_passwords'>)
>2025-09-17 10:38:57,112 - util.py[DEBUG]: Reading from /etc/openssh/sshd_config (quiet=False)
>2025-09-17 10:38:57,112 - util.py[DEBUG]: Reading 4242 bytes from /etc/openssh/sshd_config
>2025-09-17 10:38:57,113 - util.py[DEBUG]: Reading from /etc/openssh/sshd_config (quiet=False)
>2025-09-17 10:38:57,113 - util.py[DEBUG]: Reading 4242 bytes from /etc/openssh/sshd_config
>2025-09-17 10:38:57,113 - ssh_util.py[DEBUG]: line 56: option PasswordAuthentication already set to yes
>2025-09-17 10:38:57,113 - cc_set_passwords.py[DEBUG]: No need to restart SSH service, PasswordAuthentication not updated.
>2025-09-17 10:38:57,113 - handlers.py[DEBUG]: finish: modules-config/config-set-passwords: SUCCESS: config-set-passwords ran successfully and took 0.002 seconds
>2025-09-17 10:38:57,114 - modules.py[DEBUG]: Running module package-update-upgrade-install (<module 'cloudinit.config.cc_package_update_upgrade_install' from '/usr/lib/python3/site-packages/cloudinit/config/cc_package_update_upgrade_install.py'>) with frequency once-per-instance
>2025-09-17 10:38:57,114 - handlers.py[DEBUG]: start: modules-config/config-package-update-upgrade-install: running config-package-update-upgrade-install with frequency once-per-instance
>2025-09-17 10:38:57,114 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_package_update_upgrade_install - wb: [644] 25 bytes
>2025-09-17 10:38:57,115 - 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'>)
>2025-09-17 10:38:57,115 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/update_sources - wb: [644] 25 bytes
>2025-09-17 10:38:57,115 - helpers.py[DEBUG]: Running update-sources using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/update_sources'>)
>2025-09-17 10:38:57,115 - subp.py[DEBUG]: Running command ['apt-get', '--quiet', '--assume-yes', 'update'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:07,969 - performance.py[DEBUG]: Running ['apt-get', '--quiet', '--assume-yes', 'update'] took 10.854 seconds
>2025-09-17 10:39:07,969 - subp.py[DEBUG]: Running command ['apt-get', '--quiet', '--assume-yes', 'dist-upgrade'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:11,569 - performance.py[DEBUG]: Running ['apt-get', '--quiet', '--assume-yes', 'dist-upgrade'] took 3.599 seconds
>2025-09-17 10:39:11,569 - helpers.py[DEBUG]: update-sources already ran (freq=once-per-instance)
>2025-09-17 10:39:11,569 - subp.py[DEBUG]: Running command ['apt-get', '--quiet', '--assume-yes', 'install', 'salt-minion'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:23,814 - performance.py[DEBUG]: Running ['apt-get', '--quiet', '--assume-yes', 'install', 'salt-minion'] took 12.245 seconds
>2025-09-17 10:39:23,815 - handlers.py[DEBUG]: finish: modules-config/config-package-update-upgrade-install: SUCCESS: config-package-update-upgrade-install ran successfully and took 26.701 seconds
>2025-09-17 10:39:23,815 - modules.py[DEBUG]: Running module timezone (<module 'cloudinit.config.cc_timezone' from '/usr/lib/python3/site-packages/cloudinit/config/cc_timezone.py'>) with frequency once-per-instance
>2025-09-17 10:39:23,815 - handlers.py[DEBUG]: start: modules-config/config-timezone: running config-timezone with frequency once-per-instance
>2025-09-17 10:39:23,816 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_timezone - wb: [644] 25 bytes
>2025-09-17 10:39:23,817 - helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_timezone'>)
>2025-09-17 10:39:23,817 - util.py[DEBUG]: Attempting to remove /etc/localtime
>2025-09-17 10:39:23,819 - util.py[DEBUG]: Creating symbolic link from '/etc/localtime' => '/usr/share/zoneinfo/Europe/Moscow'
>2025-09-17 10:39:23,819 - handlers.py[DEBUG]: finish: modules-config/config-timezone: SUCCESS: config-timezone ran successfully and took 0.004 seconds
>2025-09-17 10:39:23,819 - modules.py[DEBUG]: Running module salt-minion (<module 'cloudinit.config.cc_salt_minion' from '/usr/lib/python3/site-packages/cloudinit/config/cc_salt_minion.py'>) with frequency once-per-instance
>2025-09-17 10:39:23,820 - handlers.py[DEBUG]: start: modules-config/config-salt-minion: running config-salt-minion with frequency once-per-instance
>2025-09-17 10:39:23,820 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_salt_minion - wb: [644] 23 bytes
>2025-09-17 10:39:23,820 - helpers.py[DEBUG]: Running config-salt-minion using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_salt_minion'>)
>2025-09-17 10:39:23,820 - helpers.py[DEBUG]: update-sources already ran (freq=once-per-instance)
>2025-09-17 10:39:23,820 - subp.py[DEBUG]: Running command ['apt-get', '--quiet', '--assume-yes', 'install', 'salt-minion'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:26,323 - performance.py[DEBUG]: Running ['apt-get', '--quiet', '--assume-yes', 'install', 'salt-minion'] took 2.502 seconds
>2025-09-17 10:39:26,324 - util.py[DEBUG]: Writing to /etc/salt/minion - wb: [644] 79 bytes
>2025-09-17 10:39:26,325 - util.py[DEBUG]: Writing to /etc/salt/grains - wb: [644] 91 bytes
>2025-09-17 10:39:26,325 - subp.py[DEBUG]: Running command ['systemctl', 'enable', 'salt-minion'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:39:26,715 - performance.py[DEBUG]: Running ['systemctl', 'enable', 'salt-minion'] took 0.390 seconds
>2025-09-17 10:39:26,715 - subp.py[DEBUG]: Running command ['systemctl', 'restart', 'salt-minion'] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:39:26,882 - performance.py[DEBUG]: Running ['systemctl', 'restart', 'salt-minion'] took 0.166 seconds
>2025-09-17 10:39:26,882 - handlers.py[DEBUG]: finish: modules-config/config-salt-minion: SUCCESS: config-salt-minion ran successfully and took 3.063 seconds
>2025-09-17 10:39:26,882 - modules.py[DEBUG]: Running module runcmd (<module 'cloudinit.config.cc_runcmd' from '/usr/lib/python3/site-packages/cloudinit/config/cc_runcmd.py'>) with frequency once-per-instance
>2025-09-17 10:39:26,883 - handlers.py[DEBUG]: start: modules-config/config-runcmd: running config-runcmd with frequency once-per-instance
>2025-09-17 10:39:26,883 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_runcmd - wb: [644] 25 bytes
>2025-09-17 10:39:26,884 - helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_runcmd'>)
>2025-09-17 10:39:26,885 - util.py[DEBUG]: Shellified 7 commands.
>2025-09-17 10:39:26,885 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/scripts/runcmd - wb: [700] 410 bytes
>2025-09-17 10:39:26,885 - handlers.py[DEBUG]: finish: modules-config/config-runcmd: SUCCESS: config-runcmd ran successfully and took 0.002 seconds
>2025-09-17 10:39:26,885 - main.py[DEBUG]: Ran 7 modules with 0 failures
>2025-09-17 10:39:26,885 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:39:26,885 - util.py[DEBUG]: Reading 12 bytes from /proc/uptime
>2025-09-17 10:39:26,886 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp_fdbtcth) - w: [644] 1569 bytes/chars
>2025-09-17 10:39:26,886 - performance.py[DEBUG]: cloud-init stage: 'modules-config' took 29.900 seconds
>2025-09-17 10:39:26,886 - handlers.py[DEBUG]: finish: modules-config: SUCCESS: running modules for config
>2025-09-17 10:39:26,886 - socket.py[INFO]: Sending sd_notify(STATUS=Waiting on external services to complete before starting the final stage.)
>2025-09-17 10:39:26,898 - performance.py[DEBUG]: Waiting to start stage final took 0.012 seconds
>2025-09-17 10:39:26,899 - socket.py[INFO]: Sending sd_notify(STATUS=Running (final stage))
>2025-09-17 10:39:26,899 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:39:26,899 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:39:26,899 - signal_handler.py[INFO]: Signal state [<function _handle_exit at 0x7f0498c62dc0>] - previously custom handler.
>2025-09-17 10:39:26,899 - handlers.py[DEBUG]: start: modules-final: running modules for final
>2025-09-17 10:39:26,899 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:39:26,899 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:39:26,899 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,904 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:39:26,905 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:39:26,905 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,905 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:39:26,905 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:39:26,905 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,906 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:39:26,906 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:39:26,906 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,906 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:39:26,906 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:39:26,906 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,910 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:39:26,910 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,910 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:39:26,910 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:39:26,910 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:39:26,910 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,915 - util.py[DEBUG]: Reading from /var/lib/cloud/data/status.json (quiet=False)
>2025-09-17 10:39:26,916 - util.py[DEBUG]: Reading 1569 bytes from /var/lib/cloud/data/status.json
>2025-09-17 10:39:26,916 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:39:26,916 - util.py[DEBUG]: Reading 12 bytes from /proc/uptime
>2025-09-17 10:39:26,916 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp7b5950n7) - w: [644] 1581 bytes/chars
>2025-09-17 10:39:26,916 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/status.json' => '../../var/lib/cloud/data/status.json'
>2025-09-17 10:39:26,916 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:39:26,916 - util.py[DEBUG]: Reading 12 bytes from /proc/uptime
>2025-09-17 10:39:26,917 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:39:26,917 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:39:26,917 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,922 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:39:26,922 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:39:26,922 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,922 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:39:26,922 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:39:26,922 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,923 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:39:26,923 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:39:26,923 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,924 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:39:26,924 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:39:26,924 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,927 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:39:26,927 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,927 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:39:26,927 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:39:26,927 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:39:26,927 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,932 - handlers.py[DEBUG]: start: modules-final/check-cache: attempting to read from cache [trust]
>2025-09-17 10:39:26,932 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
>2025-09-17 10:39:26,932 - util.py[DEBUG]: Reading 8913 bytes from /var/lib/cloud/instance/obj.pkl
>2025-09-17 10:39:26,933 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
>2025-09-17 10:39:26,933 - util.py[DEBUG]: Reading 8 bytes from /run/cloud-init/.instance-id
>2025-09-17 10:39:26,933 - stages.py[DEBUG]: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=local]
>2025-09-17 10:39:26,933 - handlers.py[DEBUG]: finish: modules-final/check-cache: SUCCESS: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=local]
>2025-09-17 10:39:26,933 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
>2025-09-17 10:39:26,934 - util.py[DEBUG]: Reading 1140 bytes from /etc/cloud/cloud.cfg
>2025-09-17 10:39:26,934 - util.py[DEBUG]: Attempting to load yaml from string of length 1140 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,938 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg (quiet=False)
>2025-09-17 10:39:26,938 - util.py[DEBUG]: Reading 35 bytes from /etc/cloud/cloud.cfg.d/90_datasource-list.cfg
>2025-09-17 10:39:26,938 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,939 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg (quiet=False)
>2025-09-17 10:39:26,939 - util.py[DEBUG]: Reading 159 bytes from /etc/cloud/cloud.cfg.d/10_bootcmd.cfg
>2025-09-17 10:39:26,939 - util.py[DEBUG]: Attempting to load yaml from string of length 159 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,939 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/09_growpart.cfg (quiet=False)
>2025-09-17 10:39:26,939 - util.py[DEBUG]: Reading 53 bytes from /etc/cloud/cloud.cfg.d/09_growpart.cfg
>2025-09-17 10:39:26,940 - util.py[DEBUG]: Attempting to load yaml from string of length 53 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,940 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
>2025-09-17 10:39:26,940 - util.py[DEBUG]: Reading 2071 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
>2025-09-17 10:39:26,940 - util.py[DEBUG]: Attempting to load yaml from string of length 2071 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,943 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
>2025-09-17 10:39:26,943 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,943 - util.py[DEBUG]: loaded blob returned None, returning default.
>2025-09-17 10:39:26,943 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:39:26,943 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:39:26,943 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,952 - log_util.py[DEBUG]: Cloud-init v. 25.1.4 running 'modules:final' at Wed, 17 Sep 2025 10:39:26 +0000. Up 38.95 seconds.
>2025-09-17 10:39:26,952 - main.py[INFO]: PID [1] started cloud-init 'modules:final'.
>2025-09-17 10:39:26,952 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
>2025-09-17 10:39:26,952 - util.py[DEBUG]: Reading 1305 bytes from /var/lib/cloud/instance/cloud-config.txt
>2025-09-17 10:39:26,952 - util.py[DEBUG]: Attempting to load yaml from string of length 1305 with allowed root types (<class 'dict'>,)
>2025-09-17 10:39:26,958 - modules.py[INFO]: Module `rightscale_userdata` has been removed from cloud-init. It may be removed from `/etc/cloud/cloud.cfg`.
>2025-09-17 10:39:26,963 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.altlinux.Distro'>
>2025-09-17 10:39:26,964 - modules.py[INFO]: Skipping modules 'phone-home' because no applicable config is provided.
>2025-09-17 10:39:26,964 - modules.py[DEBUG]: Running module scripts-per-once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/lib/python3/site-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once
>2025-09-17 10:39:26,965 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once
>2025-09-17 10:39:26,965 - util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [644] 25 bytes
>2025-09-17 10:39:26,965 - helpers.py[DEBUG]: Running config-scripts-per-once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>)
>2025-09-17 10:39:26,965 - subp.py[DEBUG]: Running command ['/var/lib/cloud/scripts/per-once/clean-root.sh'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:26,970 - subp.py[DEBUG]: Running command ['/var/lib/cloud/scripts/per-once/lvm.sh'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:27,954 - performance.py[DEBUG]: Running ['/var/lib/cloud/scripts/per-once/lvm.sh'] took 0.983 seconds
>2025-09-17 10:39:27,955 - subp.py[DEBUG]: Running command ['/var/lib/cloud/scripts/per-once/machine-id.sh'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:28,126 - performance.py[DEBUG]: Running ['/var/lib/cloud/scripts/per-once/machine-id.sh'] took 0.172 seconds
>2025-09-17 10:39:28,127 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once ran successfully and took 1.162 seconds
>2025-09-17 10:39:28,127 - modules.py[DEBUG]: Running module scripts-per-boot (<module 'cloudinit.config.cc_scripts_per_boot' from '/usr/lib/python3/site-packages/cloudinit/config/cc_scripts_per_boot.py'>) with frequency always
>2025-09-17 10:39:28,127 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always
>2025-09-17 10:39:28,127 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x7f0497ed2e80>)
>2025-09-17 10:39:28,129 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully and took 0.002 seconds
>2025-09-17 10:39:28,129 - modules.py[DEBUG]: Running module scripts-per-instance (<module 'cloudinit.config.cc_scripts_per_instance' from '/usr/lib/python3/site-packages/cloudinit/config/cc_scripts_per_instance.py'>) with frequency once-per-instance
>2025-09-17 10:39:28,129 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance
>2025-09-17 10:39:28,130 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_per_instance - wb: [644] 25 bytes
>2025-09-17 10:39:28,130 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_per_instance'>)
>2025-09-17 10:39:28,130 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance ran successfully and took 0.001 seconds
>2025-09-17 10:39:28,130 - modules.py[DEBUG]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/site-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance
>2025-09-17 10:39:28,130 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance
>2025-09-17 10:39:28,131 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_user - wb: [644] 25 bytes
>2025-09-17 10:39:28,131 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_user'>)
>2025-09-17 10:39:28,131 - subp.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts/runcmd'] with allowed return codes [0] (shell=False, capture=False)
>2025-09-17 10:39:28,516 - performance.py[DEBUG]: Running ['/var/lib/cloud/instance/scripts/runcmd'] took 0.385 seconds
>2025-09-17 10:39:28,516 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully and took 0.386 seconds
>2025-09-17 10:39:28,516 - modules.py[DEBUG]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequency once-per-instance
>2025-09-17 10:39:28,517 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance
>2025-09-17 10:39:28,517 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints - wb: [644] 25 bytes
>2025-09-17 10:39:28,518 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints'>)
>2025-09-17 10:39:28,518 - util.py[DEBUG]: Reading from /etc/openssh/sshd_config (quiet=False)
>2025-09-17 10:39:28,518 - util.py[DEBUG]: Reading 4242 bytes from /etc/openssh/sshd_config
>2025-09-17 10:39:28,519 - util.py[DEBUG]: Reading from /home/user/.ssh/authorized_keys (quiet=False)
>2025-09-17 10:39:28,519 - util.py[DEBUG]: Reading 75 bytes from /home/user/.ssh/authorized_keys
>2025-09-17 10:39:28,521 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully and took 0.004 seconds
>2025-09-17 10:39:28,521 - modules.py[DEBUG]: Running module keys-to-console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/lib/python3/site-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance
>2025-09-17 10:39:28,521 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance
>2025-09-17 10:39:28,522 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_keys_to_console - wb: [644] 25 bytes
>2025-09-17 10:39:28,522 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_keys_to_console'>)
>2025-09-17 10:39:28,522 - subp.py[DEBUG]: Running command ['/usr/libexec/cloud-init/write-ssh-key-fingerprints', '', ''] with allowed return codes [0] (shell=False, capture=True)
>2025-09-17 10:39:28,544 - performance.py[DEBUG]: Running ['/usr/libexec/cloud-init/write-ssh-key-fingerprints', '', ''] took 0.022 seconds
>2025-09-17 10:39:28,554 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully and took 0.032 seconds
>2025-09-17 10:39:28,554 - modules.py[DEBUG]: Running module final-message (<module 'cloudinit.config.cc_final_message' from '/usr/lib/python3/site-packages/cloudinit/config/cc_final_message.py'>) with frequency always
>2025-09-17 10:39:28,555 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always
>2025-09-17 10:39:28,555 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x7f0497ed2eb0>)
>2025-09-17 10:39:28,555 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:39:28,555 - util.py[DEBUG]: Reading 12 bytes from /proc/uptime
>2025-09-17 10:39:28,556 - log_util.py[DEBUG]: Cloud-init v. 25.1.4 finished at Wed, 17 Sep 2025 10:39:28 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=local].  Up 40.59 seconds
>2025-09-17 10:39:28,557 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 52 bytes
>2025-09-17 10:39:28,557 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully and took 0.002 seconds
>2025-09-17 10:39:28,557 - main.py[DEBUG]: Ran 7 modules with 0 failures
>2025-09-17 10:39:28,557 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
>2025-09-17 10:39:28,557 - util.py[DEBUG]: Reading 12 bytes from /proc/uptime
>2025-09-17 10:39:28,558 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp3a5e8nlb) - w: [644] 1571 bytes/chars
>2025-09-17 10:39:28,558 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmp5h1h6in0) - w: [644] 98 bytes/chars
>2025-09-17 10:39:28,558 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
>2025-09-17 10:39:28,558 - performance.py[DEBUG]: cloud-init stage: 'modules-final' took 1.659 seconds
>2025-09-17 10:39:28,558 - handlers.py[DEBUG]: finish: modules-final: SUCCESS: running modules for final
>2025-09-17 10:39:28,559 - socket.py[INFO]: Sending sd_notify(STATUS=Completed)
>2025-09-17 10:39:28,559 - socket.py[INFO]: Sending sd_notify(STOPPING=1)

Actions: View

Attachments on bug 56022: 19561 | 19562