2022-10-11 00:44:04,927 - util.py[DEBUG]: Cloud-init v. 21.1-15.el8 running 'init-local' at Tue, 11 Oct 2022 00:44:04 +0000. Up 10.56 seconds. 2022-10-11 00:44:04,927 - main.py[DEBUG]: No kernel command line url found. 2022-10-11 00:44:04,927 - main.py[DEBUG]: Closing stdin. 2022-10-11 00:44:04,928 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=False) 2022-10-11 00:44:04,929 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=True) 2022-10-11 00:44:04,933 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts (recursive=False) 2022-10-11 00:44:04,934 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts (recursive=True) 2022-10-11 00:44:04,935 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-instance (recursive=False) 2022-10-11 00:44:04,935 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts (recursive=True) 2022-10-11 00:44:04,936 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-once (recursive=False) 2022-10-11 00:44:04,937 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts (recursive=True) 2022-10-11 00:44:04,938 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-boot (recursive=False) 2022-10-11 00:44:04,938 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts (recursive=True) 2022-10-11 00:44:04,939 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/vendor (recursive=False) 2022-10-11 00:44:04,940 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=True) 2022-10-11 00:44:04,942 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/seed (recursive=False) 2022-10-11 00:44:04,942 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=True) 2022-10-11 00:44:04,945 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances (recursive=False) 2022-10-11 00:44:04,945 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=True) 2022-10-11 00:44:04,947 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/handlers (recursive=False) 2022-10-11 00:44:04,948 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=True) 2022-10-11 00:44:04,950 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/sem (recursive=False) 2022-10-11 00:44:04,951 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data (recursive=False) 2022-10-11 00:44:04,951 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes 2022-10-11 00:44:04,953 - util.py[DEBUG]: Restoring selinux mode for /var/log/cloud-init.log (recursive=False) 2022-10-11 00:44:04,953 - util.py[DEBUG]: Restoring selinux mode for /var/log/cloud-init.log (recursive=False) 2022-10-11 00:44:04,953 - util.py[DEBUG]: Writing to /var/lib/cloud/data/python-version - wb: [644] 3 bytes 2022-10-11 00:44:04,954 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/python-version (recursive=False) 2022-10-11 00:44:04,955 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/python-version (recursive=False) 2022-10-11 00:44:04,955 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished 2022-10-11 00:44:04,955 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net 2022-10-11 00:44:04,955 - handlers.py[DEBUG]: start: init-local/check-cache: attempting to read from cache [check] 2022-10-11 00:44:04,956 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False) 2022-10-11 00:44:04,956 - stages.py[DEBUG]: no cache found 2022-10-11 00:44:04,956 - handlers.py[DEBUG]: finish: init-local/check-cache: SUCCESS: no cache found 2022-10-11 00:44:04,956 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance 2022-10-11 00:44:04,960 - stages.py[DEBUG]: Using distro class 2022-10-11 00:44:04,961 - __init__.py[DEBUG]: Looking for data source in: ['Ec2', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM'] 2022-10-11 00:44:04,965 - __init__.py[DEBUG]: Searching for local data source in: ['DataSourceEc2Local'] 2022-10-11 00:44:04,965 - handlers.py[DEBUG]: start: init-local/search-Ec2Local: searching for local data from DataSourceEc2Local 2022-10-11 00:44:04,965 - __init__.py[DEBUG]: Seeing if we can get any data from 2022-10-11 00:44:04,966 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: New instance first boot 2022-10-11 00:44:04,966 - util.py[DEBUG]: Reading from /sys/hypervisor/uuid (quiet=False) 2022-10-11 00:44:04,966 - util.py[DEBUG]: Read 37 bytes from /sys/hypervisor/uuid 2022-10-11 00:44:04,966 - dmi.py[DEBUG]: querying dmi data /sys/class/dmi/id/product_serial 2022-10-11 00:44:04,966 - dmi.py[DEBUG]: querying dmi data /sys/class/dmi/id/chassis_asset_tag 2022-10-11 00:44:04,966 - dmi.py[DEBUG]: querying dmi data /sys/class/dmi/id/sys_vendor 2022-10-11 00:44:04,966 - DataSourceEc2.py[DEBUG]: strict_mode: warn, cloud_name=aws cloud_platform=ec2 2022-10-11 00:44:04,966 - __init__.py[DEBUG]: Stable ifnames disabled by net.ifnames=0 in /proc/cmdline 2022-10-11 00:44:04,967 - util.py[DEBUG]: Reading from /sys/class/net/eth0/carrier (quiet=False) 2022-10-11 00:44:04,967 - util.py[DEBUG]: Reading from /sys/class/net/eth0/dormant (quiet=False) 2022-10-11 00:44:04,967 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False) 2022-10-11 00:44:04,967 - util.py[DEBUG]: Read 5 bytes from /sys/class/net/eth0/operstate 2022-10-11 00:44:04,967 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:04,967 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:04,968 - dhcp.py[DEBUG]: Performing a dhcp discovery on eth0 2022-10-11 00:44:04,968 - util.py[DEBUG]: Copying /usr/sbin/dhclient to /var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient 2022-10-11 00:44:04,980 - subp.py[DEBUG]: Running command ['ip', 'link', 'set', 'dev', 'eth0', 'up'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,016 - subp.py[DEBUG]: Running command ['/var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient', '-1', '-v', '-lf', '/var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhcp.leases', '-pf', '/var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient.pid', 'eth0', '-sf', '/bin/true'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,076 - util.py[DEBUG]: All files appeared after 0 seconds: ['/var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient.pid', '/var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhcp.leases'] 2022-10-11 00:44:05,076 - util.py[DEBUG]: Reading from /var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient.pid (quiet=False) 2022-10-11 00:44:05,077 - util.py[DEBUG]: Read 0 bytes from /var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient.pid 2022-10-11 00:44:05,087 - util.py[DEBUG]: Reading from /var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient.pid (quiet=False) 2022-10-11 00:44:05,087 - util.py[DEBUG]: Read 4 bytes from /var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhclient.pid 2022-10-11 00:44:05,087 - util.py[DEBUG]: Reading from /proc/832/stat (quiet=True) 2022-10-11 00:44:05,088 - util.py[DEBUG]: Read 298 bytes from /proc/832/stat 2022-10-11 00:44:05,088 - dhcp.py[DEBUG]: killing dhclient with pid=832 2022-10-11 00:44:05,089 - util.py[DEBUG]: Reading from /var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhcp.leases (quiet=False) 2022-10-11 00:44:05,089 - util.py[DEBUG]: Read 594 bytes from /var/tmp/cloud-init/cloud-init-dhcp-yf43aui9/dhcp.leases 2022-10-11 00:44:05,089 - dhcp.py[DEBUG]: Received dhcp lease on eth0 for 172.31.82.61/255.255.240.0 2022-10-11 00:44:05,090 - __init__.py[DEBUG]: Attempting setup of ephemeral network on eth0 with 172.31.82.61/20 brd 172.31.95.255 2022-10-11 00:44:05,090 - subp.py[DEBUG]: Running command ['ip', '-family', 'inet', 'addr', 'add', '172.31.82.61/20', 'broadcast', '172.31.95.255', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,095 - subp.py[DEBUG]: Running command ['ip', '-family', 'inet', 'link', 'set', 'dev', 'eth0', 'up'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,099 - subp.py[DEBUG]: Running command ['ip', 'route', 'show', '0.0.0.0/0'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,102 - subp.py[DEBUG]: Running command ['ip', '-4', 'route', 'add', '172.31.80.1', 'dev', 'eth0', 'src', '172.31.82.61'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,105 - subp.py[DEBUG]: Running command ['ip', '-4', 'route', 'add', 'default', 'via', '172.31.80.1', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,113 - util.py[DEBUG]: Resolving URL: http://169.254.169.254 took 0.004 seconds 2022-10-11 00:44:05,113 - util.py[DEBUG]: Resolving URL: http://instance-data.:8773 took 0.000 seconds 2022-10-11 00:44:05,113 - DataSourceEc2.py[DEBUG]: Removed the following from metadata urls: ['http://instance-data.:8773'] 2022-10-11 00:44:05,114 - DataSourceEc2.py[DEBUG]: Fetching Ec2 IMDSv2 API Token 2022-10-11 00:44:05,114 - url_helper.py[DEBUG]: [0/1] open 'http://169.254.169.254/latest/api/token' with {'url': 'http://169.254.169.254/latest/api/token', 'allow_redirects': True, 'method': 'PUT', 'timeout': 50.0, 'headers': {'User-Agent': 'Cloud-Init/21.1-15.el8', 'X-aws-ec2-metadata-token-ttl-seconds': 'REDACTED'}} configuration 2022-10-11 00:44:05,121 - url_helper.py[DEBUG]: Read from http://169.254.169.254/latest/api/token (200, 56b) after 1 attempts 2022-10-11 00:44:05,121 - DataSourceEc2.py[DEBUG]: Using metadata source: 'http://169.254.169.254' 2022-10-11 00:44:05,122 - url_helper.py[DEBUG]: [0/1] open 'http://169.254.169.254/2018-09-24/meta-data/instance-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/instance-id', 'allow_redirects': True, 'method': 'GET', 'headers': {'User-Agent': 'Cloud-Init/21.1-15.el8', 'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,125 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/instance-id (200, 19b) after 1 attempts 2022-10-11 00:44:05,125 - DataSourceEc2.py[DEBUG]: Found preferred metadata version 2018-09-24 2022-10-11 00:44:05,125 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/user-data' with {'url': 'http://169.254.169.254/2018-09-24/user-data', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,128 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/user-data (200, 374b) after 1 attempts 2022-10-11 00:44:05,129 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,132 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/ (200, 306b) after 1 attempts 2022-10-11 00:44:05,132 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,138 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/ (200, 8b) after 1 attempts 2022-10-11 00:44:05,139 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/ami' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/ami', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,142 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/ami (200, 9b) after 1 attempts 2022-10-11 00:44:05,142 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/root' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/root', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,146 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/block-device-mapping/root (200, 9b) after 1 attempts 2022-10-11 00:44:05,146 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/events/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/events/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,152 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/events/ (200, 12b) after 1 attempts 2022-10-11 00:44:05,153 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/events/maintenance/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/events/maintenance/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,160 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/events/maintenance/ (200, 17b) after 1 attempts 2022-10-11 00:44:05,161 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/events/maintenance/history' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/events/maintenance/history', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,164 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/events/maintenance/history (200, 2b) after 1 attempts 2022-10-11 00:44:05,164 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/events/maintenance/scheduled' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/events/maintenance/scheduled', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,169 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/events/maintenance/scheduled (200, 2b) after 1 attempts 2022-10-11 00:44:05,169 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/hibernation/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/hibernation/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,173 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/hibernation/ (200, 10b) after 1 attempts 2022-10-11 00:44:05,173 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/hibernation/configured' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/hibernation/configured', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,183 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/hibernation/configured (200, 5b) after 1 attempts 2022-10-11 00:44:05,183 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/identity-credentials/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/identity-credentials/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,186 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/identity-credentials/ (200, 4b) after 1 attempts 2022-10-11 00:44:05,187 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/identity-credentials/ec2/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/identity-credentials/ec2/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,189 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/identity-credentials/ec2/ (200, 26b) after 1 attempts 2022-10-11 00:44:05,190 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/identity-credentials/ec2/info' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/identity-credentials/ec2/info', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,193 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/identity-credentials/ec2/info (200, 98b) after 1 attempts 2022-10-11 00:44:05,193 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/metrics/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/metrics/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,196 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/metrics/ (200, 7b) after 1 attempts 2022-10-11 00:44:05,196 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/metrics/vhostmd' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/metrics/vhostmd', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,202 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/metrics/vhostmd (200, 38b) after 1 attempts 2022-10-11 00:44:05,202 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,205 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/ (200, 11b) after 1 attempts 2022-10-11 00:44:05,205 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,208 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/ (200, 5b) after 1 attempts 2022-10-11 00:44:05,209 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,212 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/ (200, 18b) after 1 attempts 2022-10-11 00:44:05,212 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,215 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/ (200, 230b) after 1 attempts 2022-10-11 00:44:05,215 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/ipv4-associations/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/ipv4-associations/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,218 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/ipv4-associations/ (200, 13b) after 1 attempts 2022-10-11 00:44:05,219 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/ipv4-associations/52.23.167.249' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/ipv4-associations/52.23.167.249', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,222 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/ipv4-associations/52.23.167.249 (200, 12b) after 1 attempts 2022-10-11 00:44:05,222 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/device-number' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/device-number', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,225 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/device-number (200, 1b) after 1 attempts 2022-10-11 00:44:05,225 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/interface-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/interface-id', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,228 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/interface-id (200, 21b) after 1 attempts 2022-10-11 00:44:05,228 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/local-hostname' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/local-hostname', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,231 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/local-hostname (200, 28b) after 1 attempts 2022-10-11 00:44:05,232 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/local-ipv4s' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/local-ipv4s', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,235 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/local-ipv4s (200, 12b) after 1 attempts 2022-10-11 00:44:05,235 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/mac' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/mac', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,241 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/mac (200, 17b) after 1 attempts 2022-10-11 00:44:05,241 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/owner-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/owner-id', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,244 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/owner-id (200, 12b) after 1 attempts 2022-10-11 00:44:05,245 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/public-hostname' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/public-hostname', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,248 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/public-hostname (200, 41b) after 1 attempts 2022-10-11 00:44:05,248 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/public-ipv4s' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/public-ipv4s', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,251 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/public-ipv4s (200, 13b) after 1 attempts 2022-10-11 00:44:05,251 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/security-group-ids' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/security-group-ids', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,254 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/security-group-ids (200, 20b) after 1 attempts 2022-10-11 00:44:05,254 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/security-groups' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/security-groups', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,262 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/security-groups (200, 15b) after 1 attempts 2022-10-11 00:44:05,263 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/subnet-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/subnet-id', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,266 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/subnet-id (200, 24b) after 1 attempts 2022-10-11 00:44:05,266 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/subnet-ipv4-cidr-block' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/subnet-ipv4-cidr-block', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,269 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/subnet-ipv4-cidr-block (200, 14b) after 1 attempts 2022-10-11 00:44:05,269 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-id', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,273 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-id (200, 21b) after 1 attempts 2022-10-11 00:44:05,273 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-ipv4-cidr-block' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-ipv4-cidr-block', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,276 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-ipv4-cidr-block (200, 13b) after 1 attempts 2022-10-11 00:44:05,276 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-ipv4-cidr-blocks' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-ipv4-cidr-blocks', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,279 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/network/interfaces/macs/12:4a:36:a2:a1:1d/vpc-ipv4-cidr-blocks (200, 13b) after 1 attempts 2022-10-11 00:44:05,279 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/placement/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/placement/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,282 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/placement/ (200, 17b) after 1 attempts 2022-10-11 00:44:05,282 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/placement/availability-zone' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/placement/availability-zone', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,285 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/placement/availability-zone (200, 10b) after 1 attempts 2022-10-11 00:44:05,286 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/public-keys/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/public-keys/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,289 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/public-keys/ (200, 9b) after 1 attempts 2022-10-11 00:44:05,289 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/public-keys/0/openssh-key' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/public-keys/0/openssh-key', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,292 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/public-keys/0/openssh-key (200, 389b) after 1 attempts 2022-10-11 00:44:05,292 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/services/' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/services/', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,302 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/services/ (200, 16b) after 1 attempts 2022-10-11 00:44:05,303 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/services/domain' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/services/domain', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,306 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/services/domain (200, 13b) after 1 attempts 2022-10-11 00:44:05,306 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/services/partition' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/services/partition', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,309 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/services/partition (200, 3b) after 1 attempts 2022-10-11 00:44:05,310 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/ami-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/ami-id', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,313 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/ami-id (200, 21b) after 1 attempts 2022-10-11 00:44:05,313 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/ami-launch-index' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/ami-launch-index', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,317 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/ami-launch-index (200, 1b) after 1 attempts 2022-10-11 00:44:05,317 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/ami-manifest-path' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/ami-manifest-path', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,320 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/ami-manifest-path (200, 9b) after 1 attempts 2022-10-11 00:44:05,321 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/hostname' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/hostname', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,324 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/hostname (200, 28b) after 1 attempts 2022-10-11 00:44:05,324 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/instance-action' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/instance-action', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,327 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/instance-action (200, 4b) after 1 attempts 2022-10-11 00:44:05,327 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/instance-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/instance-id', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,330 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/instance-id (200, 19b) after 1 attempts 2022-10-11 00:44:05,330 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/instance-type' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/instance-type', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,333 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/instance-type (200, 8b) after 1 attempts 2022-10-11 00:44:05,333 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/local-hostname' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/local-hostname', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,336 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/local-hostname (200, 28b) after 1 attempts 2022-10-11 00:44:05,336 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/local-ipv4' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/local-ipv4', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,339 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/local-ipv4 (200, 12b) after 1 attempts 2022-10-11 00:44:05,339 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/mac' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/mac', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,342 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/mac (200, 17b) after 1 attempts 2022-10-11 00:44:05,342 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/profile' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/profile', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,346 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/profile (200, 11b) after 1 attempts 2022-10-11 00:44:05,346 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/public-hostname' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/public-hostname', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,349 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/public-hostname (200, 41b) after 1 attempts 2022-10-11 00:44:05,349 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/public-ipv4' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/public-ipv4', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,353 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/public-ipv4 (200, 13b) after 1 attempts 2022-10-11 00:44:05,353 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/reservation-id' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/reservation-id', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,356 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/reservation-id (200, 19b) after 1 attempts 2022-10-11 00:44:05,356 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/meta-data/security-groups' with {'url': 'http://169.254.169.254/2018-09-24/meta-data/security-groups', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,359 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/meta-data/security-groups (200, 15b) after 1 attempts 2022-10-11 00:44:05,360 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/dynamic/instance-identity' with {'url': 'http://169.254.169.254/2018-09-24/dynamic/instance-identity', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,364 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/dynamic/instance-identity (200, 33b) after 1 attempts 2022-10-11 00:44:05,364 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/rsa2048' with {'url': 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/rsa2048', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,367 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/dynamic/instance-identity/rsa2048 (200, 1503b) after 1 attempts 2022-10-11 00:44:05,367 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/pkcs7' with {'url': 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/pkcs7', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,370 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/dynamic/instance-identity/pkcs7 (200, 1183b) after 1 attempts 2022-10-11 00:44:05,370 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/signature' with {'url': 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/signature', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,373 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/dynamic/instance-identity/signature (200, 174b) after 1 attempts 2022-10-11 00:44:05,374 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/document' with {'url': 'http://169.254.169.254/2018-09-24/dynamic/instance-identity/document', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'X-aws-ec2-metadata-token': 'REDACTED'}} configuration 2022-10-11 00:44:05,377 - url_helper.py[DEBUG]: Read from http://169.254.169.254/2018-09-24/dynamic/instance-identity/document (200, 489b) after 1 attempts 2022-10-11 00:44:05,377 - util.py[DEBUG]: Crawl of metadata service took 0.268 seconds 2022-10-11 00:44:05,377 - subp.py[DEBUG]: Running command ['ip', '-4', 'route', 'del', 'default', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,381 - subp.py[DEBUG]: Running command ['ip', '-4', 'route', 'del', '172.31.80.1', 'dev', 'eth0', 'src', '172.31.82.61'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,384 - subp.py[DEBUG]: Running command ['ip', '-family', 'inet', 'link', 'set', 'dev', 'eth0', 'down'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,387 - subp.py[DEBUG]: Running command ['ip', '-family', 'inet', 'addr', 'del', '172.31.82.61/20', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,394 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmpebtk70hb) - w: [600] 11442 bytes/chars 2022-10-11 00:44:05,395 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data.json (via temporary file /run/cloud-init/tmpatsyeoqf) - w: [644] 8241 bytes/chars 2022-10-11 00:44:05,395 - handlers.py[DEBUG]: finish: init-local/search-Ec2Local: SUCCESS: found local data from DataSourceEc2Local 2022-10-11 00:44:05,395 - stages.py[INFO]: Loaded datasource DataSourceEc2Local - DataSourceEc2Local 2022-10-11 00:44:05,395 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) 2022-10-11 00:44:05,396 - util.py[DEBUG]: Read 1257 bytes from /etc/cloud/cloud.cfg 2022-10-11 00:44:05,396 - util.py[DEBUG]: Attempting to load yaml from string of length 1257 with allowed root types (,) 2022-10-11 00:44:05,403 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) 2022-10-11 00:44:05,403 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg 2022-10-11 00:44:05,403 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,) 2022-10-11 00:44:05,407 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg (quiet=False) 2022-10-11 00:44:05,407 - util.py[DEBUG]: Read 48 bytes from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg 2022-10-11 00:44:05,407 - util.py[DEBUG]: Attempting to load yaml from string of length 48 with allowed root types (,) 2022-10-11 00:44:05,408 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) 2022-10-11 00:44:05,408 - util.py[DEBUG]: Read 31 bytes from /run/cloud-init/cloud.cfg 2022-10-11 00:44:05,408 - util.py[DEBUG]: Attempting to load yaml from string of length 31 with allowed root types (,) 2022-10-11 00:44:05,409 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) 2022-10-11 00:44:05,409 - util.py[DEBUG]: loaded blob returned None, returning default. 2022-10-11 00:44:05,409 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance 2022-10-11 00:44:05,409 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/i-024f3ce3512b468d1' 2022-10-11 00:44:05,410 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1 (recursive=True) 2022-10-11 00:44:05,411 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/handlers (recursive=False) 2022-10-11 00:44:05,412 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1 (recursive=True) 2022-10-11 00:44:05,413 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/scripts (recursive=False) 2022-10-11 00:44:05,413 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1 (recursive=True) 2022-10-11 00:44:05,415 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem (recursive=False) 2022-10-11 00:44:05,415 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource (quiet=False) 2022-10-11 00:44:05,415 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource - wb: [644] 39 bytes 2022-10-11 00:44:05,416 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource (recursive=False) 2022-10-11 00:44:05,416 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource (recursive=False) 2022-10-11 00:44:05,417 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 39 bytes 2022-10-11 00:44:05,417 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-datasource (recursive=False) 2022-10-11 00:44:05,418 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-datasource (recursive=False) 2022-10-11 00:44:05,418 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False) 2022-10-11 00:44:05,418 - stages.py[DEBUG]: previous iid found to be NO_PREVIOUS_INSTANCE_ID 2022-10-11 00:44:05,418 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 20 bytes 2022-10-11 00:44:05,419 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/instance-id (recursive=False) 2022-10-11 00:44:05,419 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/instance-id (recursive=False) 2022-10-11 00:44:05,420 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 20 bytes 2022-10-11 00:44:05,420 - util.py[DEBUG]: Restoring selinux mode for /run/cloud-init/.instance-id (recursive=False) 2022-10-11 00:44:05,420 - util.py[DEBUG]: Restoring selinux mode for /run/cloud-init/.instance-id (recursive=False) 2022-10-11 00:44:05,421 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 24 bytes 2022-10-11 00:44:05,421 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-instance-id (recursive=False) 2022-10-11 00:44:05,422 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-instance-id (recursive=False) 2022-10-11 00:44:05,422 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 11827 bytes 2022-10-11 00:44:05,423 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/obj.pkl (recursive=False) 2022-10-11 00:44:05,424 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/obj.pkl (recursive=False) 2022-10-11 00:44:05,424 - main.py[DEBUG]: [local] init will now be targeting instance id: i-024f3ce3512b468d1. new=True 2022-10-11 00:44:05,424 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) 2022-10-11 00:44:05,424 - util.py[DEBUG]: Read 1257 bytes from /etc/cloud/cloud.cfg 2022-10-11 00:44:05,424 - util.py[DEBUG]: Attempting to load yaml from string of length 1257 with allowed root types (,) 2022-10-11 00:44:05,432 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) 2022-10-11 00:44:05,432 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg 2022-10-11 00:44:05,432 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,) 2022-10-11 00:44:05,436 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg (quiet=False) 2022-10-11 00:44:05,436 - util.py[DEBUG]: Read 48 bytes from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg 2022-10-11 00:44:05,436 - util.py[DEBUG]: Attempting to load yaml from string of length 48 with allowed root types (,) 2022-10-11 00:44:05,437 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) 2022-10-11 00:44:05,437 - util.py[DEBUG]: Read 31 bytes from /run/cloud-init/cloud.cfg 2022-10-11 00:44:05,437 - util.py[DEBUG]: Attempting to load yaml from string of length 31 with allowed root types (,) 2022-10-11 00:44:05,437 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) 2022-10-11 00:44:05,437 - util.py[DEBUG]: loaded blob returned None, returning default. 2022-10-11 00:44:05,438 - stages.py[DEBUG]: Using distro class 2022-10-11 00:44:05,439 - cc_set_hostname.py[DEBUG]: Setting the hostname to ip-172-31-82-61.ec2.internal (ip-172-31-82-61) 2022-10-11 00:44:05,439 - subp.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'ip-172-31-82-61.ec2.internal'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,525 - __init__.py[DEBUG]: Non-persistently setting the system hostname to ip-172-31-82-61.ec2.internal 2022-10-11 00:44:05,526 - subp.py[DEBUG]: Running command ['hostname', 'ip-172-31-82-61.ec2.internal'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,539 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/set-hostname (via temporary file /var/lib/cloud/data/tmp675t7gzd) - w: [644] 76 bytes/chars 2022-10-11 00:44:05,541 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False) 2022-10-11 00:44:05,541 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address 2022-10-11 00:44:05,541 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:05,541 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:05,541 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False) 2022-10-11 00:44:05,541 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type 2022-10-11 00:44:05,542 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False) 2022-10-11 00:44:05,542 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent 2022-10-11 00:44:05,542 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False) 2022-10-11 00:44:05,542 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address 2022-10-11 00:44:05,542 - __init__.py[DEBUG]: ovs-vsctl not in PATH; not detecting Open vSwitch interfaces 2022-10-11 00:44:05,542 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False) 2022-10-11 00:44:05,542 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False) 2022-10-11 00:44:05,542 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type 2022-10-11 00:44:05,542 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False) 2022-10-11 00:44:05,542 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent 2022-10-11 00:44:05,543 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:05,543 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:05,543 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:05,543 - util.py[DEBUG]: Reading from /sys/class/net/lo/type (quiet=False) 2022-10-11 00:44:05,543 - util.py[DEBUG]: Read 4 bytes from /sys/class/net/lo/type 2022-10-11 00:44:05,543 - util.py[DEBUG]: Reading from /sys/class/net/eth0/type (quiet=False) 2022-10-11 00:44:05,543 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/type 2022-10-11 00:44:05,543 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:05,543 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False) 2022-10-11 00:44:05,543 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False) 2022-10-11 00:44:05,544 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False) 2022-10-11 00:44:05,544 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False) 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False) 2022-10-11 00:44:05,544 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False) 2022-10-11 00:44:05,544 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:05,544 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:05,544 - util.py[DEBUG]: Reading from /sys/class/net/lo/type (quiet=False) 2022-10-11 00:44:05,545 - util.py[DEBUG]: Read 4 bytes from /sys/class/net/lo/type 2022-10-11 00:44:05,545 - util.py[DEBUG]: Reading from /sys/class/net/eth0/type (quiet=False) 2022-10-11 00:44:05,545 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/type 2022-10-11 00:44:05,545 - networking.py[DEBUG]: net: all expected physical devices present 2022-10-11 00:44:05,545 - stages.py[DEBUG]: applying net config names for {'version': 2, 'ethernets': {'eth0': {'dhcp4': True, 'dhcp6': False, 'match': {'macaddress': '12:4a:36:a2:a1:1d'}, 'set-name': 'eth0'}}} 2022-10-11 00:44:05,545 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:05,545 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False) 2022-10-11 00:44:05,545 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type 2022-10-11 00:44:05,545 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False) 2022-10-11 00:44:05,545 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent 2022-10-11 00:44:05,545 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False) 2022-10-11 00:44:05,545 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address 2022-10-11 00:44:05,545 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False) 2022-10-11 00:44:05,546 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False) 2022-10-11 00:44:05,546 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type 2022-10-11 00:44:05,546 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False) 2022-10-11 00:44:05,546 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent 2022-10-11 00:44:05,546 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:05,546 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:05,546 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:05,546 - util.py[DEBUG]: Reading from /sys/class/net/lo/operstate (quiet=False) 2022-10-11 00:44:05,546 - util.py[DEBUG]: Read 8 bytes from /sys/class/net/lo/operstate 2022-10-11 00:44:05,546 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False) 2022-10-11 00:44:05,546 - util.py[DEBUG]: Read 5 bytes from /sys/class/net/eth0/operstate 2022-10-11 00:44:05,547 - subp.py[DEBUG]: Running command ['ip', '-6', 'addr', 'show', 'permanent', 'scope', 'global'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,551 - subp.py[DEBUG]: Running command ['ip', '-4', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:05,555 - __init__.py[DEBUG]: no work necessary for renaming of [['12:4a:36:a2:a1:1d', 'eth0', 'vif', None]] 2022-10-11 00:44:05,555 - stages.py[INFO]: Applying network configuration from ds bringup=False: {'version': 2, 'ethernets': {'eth0': {'dhcp4': True, 'dhcp6': False, 'match': {'macaddress': '12:4a:36:a2:a1:1d'}, 'set-name': 'eth0'}}} 2022-10-11 00:44:05,555 - __init__.py[DEBUG]: Selected renderer 'sysconfig' from priority list: None 2022-10-11 00:44:05,556 - network_state.py[DEBUG]: v2(ethernets) -> v1(physical): {'type': 'physical', 'name': 'eth0', 'mac_address': '12:4a:36:a2:a1:1d', 'match': {'macaddress': '12:4a:36:a2:a1:1d'}, 'subnets': [{'type': 'dhcp4'}]} 2022-10-11 00:44:05,558 - network_state.py[DEBUG]: v2_common: handling config: {'eth0': {'dhcp4': True, 'dhcp6': False, 'match': {'macaddress': '12:4a:36:a2:a1:1d'}, 'set-name': 'eth0'}} 2022-10-11 00:44:05,559 - util.py[DEBUG]: Writing to /etc/sysconfig/network-scripts/ifcfg-eth0 - wb: [644] 159 bytes 2022-10-11 00:44:05,560 - util.py[DEBUG]: Restoring selinux mode for /etc/sysconfig/network-scripts/ifcfg-eth0 (recursive=False) 2022-10-11 00:44:05,561 - util.py[DEBUG]: Restoring selinux mode for /etc/sysconfig/network-scripts/ifcfg-eth0 (recursive=False) 2022-10-11 00:44:05,562 - util.py[DEBUG]: Writing to /etc/udev/rules.d/70-persistent-net.rules - wb: [644] 96 bytes 2022-10-11 00:44:05,562 - util.py[DEBUG]: Restoring selinux mode for /etc/udev/rules.d/70-persistent-net.rules (recursive=False) 2022-10-11 00:44:05,563 - util.py[DEBUG]: Restoring selinux mode for /etc/udev/rules.d/70-persistent-net.rules (recursive=False) 2022-10-11 00:44:05,564 - sysconfig.py[DEBUG]: Enabled ifcfg-rh NetworkManager plugins 2022-10-11 00:44:05,564 - util.py[DEBUG]: Reading from /etc/sysconfig/network (quiet=True) 2022-10-11 00:44:05,564 - util.py[DEBUG]: Read 30 bytes from /etc/sysconfig/network 2022-10-11 00:44:05,565 - util.py[DEBUG]: Writing to /etc/sysconfig/network - wb: [644] 102 bytes 2022-10-11 00:44:05,565 - util.py[DEBUG]: Restoring selinux mode for /etc/sysconfig/network (recursive=False) 2022-10-11 00:44:05,566 - util.py[DEBUG]: Restoring selinux mode for /etc/sysconfig/network (recursive=False) 2022-10-11 00:44:05,567 - main.py[DEBUG]: [local] Exiting. datasource DataSourceEc2Local not in local mode. 2022-10-11 00:44:05,568 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmptz_m8cpy) - w: [644] 490 bytes/chars 2022-10-11 00:44:05,568 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) 2022-10-11 00:44:05,568 - util.py[DEBUG]: Read 11 bytes from /proc/uptime 2022-10-11 00:44:05,568 - util.py[DEBUG]: cloud-init mode 'init' took 0.708 seconds (0.71) 2022-10-11 00:44:05,568 - handlers.py[DEBUG]: finish: init-local: SUCCESS: searching for local datasources 2022-10-11 00:44:07,007 - util.py[DEBUG]: Cloud-init v. 21.1-15.el8 running 'init' at Tue, 11 Oct 2022 00:44:06 +0000. Up 12.64 seconds. 2022-10-11 00:44:07,007 - main.py[DEBUG]: No kernel command line url found. 2022-10-11 00:44:07,007 - main.py[DEBUG]: Closing stdin. 2022-10-11 00:44:07,007 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud (recursive=False) 2022-10-11 00:44:07,008 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts (recursive=False) 2022-10-11 00:44:07,009 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-instance (recursive=False) 2022-10-11 00:44:07,009 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-once (recursive=False) 2022-10-11 00:44:07,010 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/per-boot (recursive=False) 2022-10-11 00:44:07,010 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/scripts/vendor (recursive=False) 2022-10-11 00:44:07,011 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/seed (recursive=False) 2022-10-11 00:44:07,011 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances (recursive=False) 2022-10-11 00:44:07,012 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/handlers (recursive=False) 2022-10-11 00:44:07,012 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/sem (recursive=False) 2022-10-11 00:44:07,012 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data (recursive=False) 2022-10-11 00:44:07,013 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes 2022-10-11 00:44:07,014 - util.py[DEBUG]: Restoring selinux mode for /var/log/cloud-init.log (recursive=False) 2022-10-11 00:44:07,016 - util.py[DEBUG]: Restoring selinux mode for /var/log/cloud-init.log (recursive=False) 2022-10-11 00:44:07,017 - subp.py[DEBUG]: Running command ['ip', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,022 - subp.py[DEBUG]: Running command ['ip', '-o', 'route', 'list'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,025 - subp.py[DEBUG]: Running command ['ip', '--oneline', '-6', 'route', 'list', 'table', 'all'] with allowed return codes [0, 1] (shell=False, capture=True) 2022-10-11 00:44:07,029 - main.py[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early. 2022-10-11 00:44:07,029 - main.py[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early. 2022-10-11 00:44:07,030 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust] 2022-10-11 00:44:07,030 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False) 2022-10-11 00:44:07,030 - util.py[DEBUG]: Read 11827 bytes from /var/lib/cloud/instance/obj.pkl 2022-10-11 00:44:07,034 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False) 2022-10-11 00:44:07,034 - util.py[DEBUG]: Read 20 bytes from /run/cloud-init/.instance-id 2022-10-11 00:44:07,034 - stages.py[DEBUG]: restored from cache with run check: DataSourceEc2Local 2022-10-11 00:44:07,034 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceEc2Local 2022-10-11 00:44:07,034 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) 2022-10-11 00:44:07,034 - util.py[DEBUG]: Read 1257 bytes from /etc/cloud/cloud.cfg 2022-10-11 00:44:07,034 - util.py[DEBUG]: Attempting to load yaml from string of length 1257 with allowed root types (,) 2022-10-11 00:44:07,043 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) 2022-10-11 00:44:07,043 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg 2022-10-11 00:44:07,043 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,) 2022-10-11 00:44:07,047 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg (quiet=False) 2022-10-11 00:44:07,047 - util.py[DEBUG]: Read 48 bytes from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg 2022-10-11 00:44:07,047 - util.py[DEBUG]: Attempting to load yaml from string of length 48 with allowed root types (,) 2022-10-11 00:44:07,048 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) 2022-10-11 00:44:07,048 - util.py[DEBUG]: Read 31 bytes from /run/cloud-init/cloud.cfg 2022-10-11 00:44:07,048 - util.py[DEBUG]: Attempting to load yaml from string of length 31 with allowed root types (,) 2022-10-11 00:44:07,048 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) 2022-10-11 00:44:07,048 - util.py[DEBUG]: loaded blob returned None, returning default. 2022-10-11 00:44:07,049 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance 2022-10-11 00:44:07,049 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/i-024f3ce3512b468d1' 2022-10-11 00:44:07,050 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/handlers (recursive=False) 2022-10-11 00:44:07,051 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/scripts (recursive=False) 2022-10-11 00:44:07,051 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem (recursive=False) 2022-10-11 00:44:07,052 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource (quiet=False) 2022-10-11 00:44:07,052 - util.py[DEBUG]: Read 39 bytes from /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource 2022-10-11 00:44:07,052 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource - wb: [644] 39 bytes 2022-10-11 00:44:07,063 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource (recursive=False) 2022-10-11 00:44:07,064 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/datasource (recursive=False) 2022-10-11 00:44:07,065 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 39 bytes 2022-10-11 00:44:07,066 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-datasource (recursive=False) 2022-10-11 00:44:07,067 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-datasource (recursive=False) 2022-10-11 00:44:07,067 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False) 2022-10-11 00:44:07,068 - util.py[DEBUG]: Read 20 bytes from /var/lib/cloud/data/instance-id 2022-10-11 00:44:07,068 - stages.py[DEBUG]: previous iid found to be i-024f3ce3512b468d1 2022-10-11 00:44:07,068 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 20 bytes 2022-10-11 00:44:07,069 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/instance-id (recursive=False) 2022-10-11 00:44:07,070 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/instance-id (recursive=False) 2022-10-11 00:44:07,070 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 20 bytes 2022-10-11 00:44:07,071 - util.py[DEBUG]: Restoring selinux mode for /run/cloud-init/.instance-id (recursive=False) 2022-10-11 00:44:07,071 - util.py[DEBUG]: Restoring selinux mode for /run/cloud-init/.instance-id (recursive=False) 2022-10-11 00:44:07,071 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 20 bytes 2022-10-11 00:44:07,073 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-instance-id (recursive=False) 2022-10-11 00:44:07,074 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-instance-id (recursive=False) 2022-10-11 00:44:07,074 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 11840 bytes 2022-10-11 00:44:07,076 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/obj.pkl (recursive=False) 2022-10-11 00:44:07,076 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/obj.pkl (recursive=False) 2022-10-11 00:44:07,077 - main.py[DEBUG]: [net] init will now be targeting instance id: i-024f3ce3512b468d1. new=False 2022-10-11 00:44:07,077 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) 2022-10-11 00:44:07,077 - util.py[DEBUG]: Read 1257 bytes from /etc/cloud/cloud.cfg 2022-10-11 00:44:07,077 - util.py[DEBUG]: Attempting to load yaml from string of length 1257 with allowed root types (,) 2022-10-11 00:44:07,084 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) 2022-10-11 00:44:07,084 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg 2022-10-11 00:44:07,084 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,) 2022-10-11 00:44:07,088 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg (quiet=False) 2022-10-11 00:44:07,088 - util.py[DEBUG]: Read 48 bytes from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg 2022-10-11 00:44:07,088 - util.py[DEBUG]: Attempting to load yaml from string of length 48 with allowed root types (,) 2022-10-11 00:44:07,089 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) 2022-10-11 00:44:07,089 - util.py[DEBUG]: Read 31 bytes from /run/cloud-init/cloud.cfg 2022-10-11 00:44:07,089 - util.py[DEBUG]: Attempting to load yaml from string of length 31 with allowed root types (,) 2022-10-11 00:44:07,090 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) 2022-10-11 00:44:07,090 - util.py[DEBUG]: loaded blob returned None, returning default. 2022-10-11 00:44:07,091 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False) 2022-10-11 00:44:07,091 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address 2022-10-11 00:44:07,091 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:07,091 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:07,092 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False) 2022-10-11 00:44:07,092 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type 2022-10-11 00:44:07,092 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False) 2022-10-11 00:44:07,092 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent 2022-10-11 00:44:07,092 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False) 2022-10-11 00:44:07,092 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address 2022-10-11 00:44:07,092 - __init__.py[DEBUG]: ovs-vsctl not in PATH; not detecting Open vSwitch interfaces 2022-10-11 00:44:07,092 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False) 2022-10-11 00:44:07,092 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False) 2022-10-11 00:44:07,092 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type 2022-10-11 00:44:07,092 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False) 2022-10-11 00:44:07,093 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent 2022-10-11 00:44:07,093 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:07,093 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:07,093 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:07,093 - util.py[DEBUG]: Reading from /sys/class/net/lo/type (quiet=False) 2022-10-11 00:44:07,093 - util.py[DEBUG]: Read 4 bytes from /sys/class/net/lo/type 2022-10-11 00:44:07,093 - util.py[DEBUG]: Reading from /sys/class/net/eth0/type (quiet=False) 2022-10-11 00:44:07,093 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/type 2022-10-11 00:44:07,093 - __init__.py[DEBUG]: Datasource DataSourceEc2Local not updated for events: System boot 2022-10-11 00:44:07,093 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update on 'System boot' event 2022-10-11 00:44:07,093 - stages.py[DEBUG]: applying net config names for {'version': 2, 'ethernets': {'eth0': {'dhcp4': True, 'dhcp6': False, 'match': {'macaddress': '12:4a:36:a2:a1:1d'}, 'set-name': 'eth0'}}} 2022-10-11 00:44:07,094 - stages.py[DEBUG]: Using distro class 2022-10-11 00:44:07,095 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:07,095 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False) 2022-10-11 00:44:07,095 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type 2022-10-11 00:44:07,095 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False) 2022-10-11 00:44:07,095 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent 2022-10-11 00:44:07,095 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False) 2022-10-11 00:44:07,095 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address 2022-10-11 00:44:07,095 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False) 2022-10-11 00:44:07,095 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False) 2022-10-11 00:44:07,095 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type 2022-10-11 00:44:07,095 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False) 2022-10-11 00:44:07,096 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent 2022-10-11 00:44:07,096 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False) 2022-10-11 00:44:07,096 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address 2022-10-11 00:44:07,096 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) 2022-10-11 00:44:07,096 - util.py[DEBUG]: Reading from /sys/class/net/lo/operstate (quiet=False) 2022-10-11 00:44:07,096 - util.py[DEBUG]: Read 8 bytes from /sys/class/net/lo/operstate 2022-10-11 00:44:07,096 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False) 2022-10-11 00:44:07,096 - util.py[DEBUG]: Read 3 bytes from /sys/class/net/eth0/operstate 2022-10-11 00:44:07,096 - subp.py[DEBUG]: Running command ['ip', '-6', 'addr', 'show', 'permanent', 'scope', 'global'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,100 - subp.py[DEBUG]: Running command ['ip', '-4', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,103 - __init__.py[DEBUG]: no work necessary for renaming of [['12:4a:36:a2:a1:1d', 'eth0', 'vif', None]] 2022-10-11 00:44:07,104 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource 2022-10-11 00:44:07,104 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource 2022-10-11 00:44:07,104 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/user-data.txt - wb: [600] 374 bytes 2022-10-11 00:44:07,105 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/user-data.txt (recursive=False) 2022-10-11 00:44:07,106 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/user-data.txt (recursive=False) 2022-10-11 00:44:07,111 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/user-data.txt.i - wb: [600] 792 bytes 2022-10-11 00:44:07,112 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/user-data.txt.i (recursive=False) 2022-10-11 00:44:07,112 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/user-data.txt.i (recursive=False) 2022-10-11 00:44:07,113 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data.txt - wb: [600] 0 bytes 2022-10-11 00:44:07,115 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data.txt (recursive=False) 2022-10-11 00:44:07,115 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data.txt (recursive=False) 2022-10-11 00:44:07,117 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data.txt.i - wb: [600] 308 bytes 2022-10-11 00:44:07,117 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data.txt.i (recursive=False) 2022-10-11 00:44:07,118 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data.txt.i (recursive=False) 2022-10-11 00:44:07,118 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data2.txt - wb: [600] 0 bytes 2022-10-11 00:44:07,119 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data2.txt (recursive=False) 2022-10-11 00:44:07,120 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data2.txt (recursive=False) 2022-10-11 00:44:07,121 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data2.txt.i - wb: [600] 308 bytes 2022-10-11 00:44:07,121 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data2.txt.i (recursive=False) 2022-10-11 00:44:07,122 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/vendor-data2.txt.i (recursive=False) 2022-10-11 00:44:07,123 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False) 2022-10-11 00:44:07,123 - util.py[DEBUG]: Read 76 bytes from /var/lib/cloud/data/set-hostname 2022-10-11 00:44:07,123 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set-hostname 2022-10-11 00:44:07,124 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/consume_data - wb: [644] 24 bytes 2022-10-11 00:44:07,124 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/consume_data (recursive=False) 2022-10-11 00:44:07,125 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/consume_data (recursive=False) 2022-10-11 00:44:07,125 - helpers.py[DEBUG]: Running consume_data using lock () 2022-10-11 00:44:07,125 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data 2022-10-11 00:44:07,126 - launch_index.py[DEBUG]: Discarding 0 multipart messages which do not match launch index 0 2022-10-11 00:44:07,126 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] 2022-10-11 00:44:07,126 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']] 2022-10-11 00:44:07,126 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']] 2022-10-11 00:44:07,126 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']] 2022-10-11 00:44:07,126 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']] 2022-10-11 00:44:07,127 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance 2022-10-11 00:44:07,127 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance 2022-10-11 00:44:07,127 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance 2022-10-11 00:44:07,127 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance 2022-10-11 00:44:07,127 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance 2022-10-11 00:44:07,127 - __init__.py[DEBUG]: {'Content-Disposition': 'attachment; filename="common.sh"', 'Content-Transfer-Encoding': '7bit', 'Content-Type': 'text/x-shellscript', 'Mime-Version': '1.0'} 2022-10-11 00:44:07,127 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (text/x-shellscript, common.sh, 2) with frequency once-per-instance 2022-10-11 00:44:07,127 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/scripts/common.sh - wb: [700] 150 bytes 2022-10-11 00:44:07,128 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/scripts/common.sh (recursive=False) 2022-10-11 00:44:07,129 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/scripts/common.sh (recursive=False) 2022-10-11 00:44:07,129 - __init__.py[DEBUG]: {'Content-Disposition': 'attachment; filename="configure.sh"', 'Content-Transfer-Encoding': '7bit', 'Content-Type': 'text/x-shellscript', 'Mime-Version': '1.0'} 2022-10-11 00:44:07,129 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (text/x-shellscript, configure.sh, 2) with frequency once-per-instance 2022-10-11 00:44:07,129 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/scripts/configure.sh - wb: [700] 122 bytes 2022-10-11 00:44:07,130 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/scripts/configure.sh (recursive=False) 2022-10-11 00:44:07,130 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/scripts/configure.sh (recursive=False) 2022-10-11 00:44:07,131 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance 2022-10-11 00:44:07,131 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/cloud-config.txt - wb: [600] 0 bytes 2022-10-11 00:44:07,131 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/cloud-config.txt (recursive=False) 2022-10-11 00:44:07,132 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/cloud-config.txt (recursive=False) 2022-10-11 00:44:07,133 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance 2022-10-11 00:44:07,133 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance 2022-10-11 00:44:07,133 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance 2022-10-11 00:44:07,133 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance 2022-10-11 00:44:07,133 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data 2022-10-11 00:44:07,133 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data 2022-10-11 00:44:07,133 - stages.py[DEBUG]: no vendordata from datasource 2022-10-11 00:44:07,133 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data 2022-10-11 00:44:07,133 - handlers.py[DEBUG]: start: init-network/consume-vendor-data2: reading and applying vendor-data2 2022-10-11 00:44:07,133 - stages.py[DEBUG]: no vendordata2 from datasource 2022-10-11 00:44:07,133 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data2: SUCCESS: reading and applying vendor-data2 2022-10-11 00:44:07,134 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False) 2022-10-11 00:44:07,134 - util.py[DEBUG]: Read 1257 bytes from /etc/cloud/cloud.cfg 2022-10-11 00:44:07,134 - util.py[DEBUG]: Attempting to load yaml from string of length 1257 with allowed root types (,) 2022-10-11 00:44:07,141 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) 2022-10-11 00:44:07,141 - util.py[DEBUG]: Read 2070 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg 2022-10-11 00:44:07,141 - util.py[DEBUG]: Attempting to load yaml from string of length 2070 with allowed root types (,) 2022-10-11 00:44:07,145 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg (quiet=False) 2022-10-11 00:44:07,145 - util.py[DEBUG]: Read 48 bytes from /etc/cloud/cloud.cfg.d/00-rhel-default-user.cfg 2022-10-11 00:44:07,145 - util.py[DEBUG]: Attempting to load yaml from string of length 48 with allowed root types (,) 2022-10-11 00:44:07,146 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) 2022-10-11 00:44:07,146 - util.py[DEBUG]: Read 31 bytes from /run/cloud-init/cloud.cfg 2022-10-11 00:44:07,146 - util.py[DEBUG]: Attempting to load yaml from string of length 31 with allowed root types (,) 2022-10-11 00:44:07,147 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) 2022-10-11 00:44:07,147 - util.py[DEBUG]: loaded blob returned None, returning default. 2022-10-11 00:44:07,147 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) 2022-10-11 00:44:07,147 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt 2022-10-11 00:44:07,147 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) 2022-10-11 00:44:07,147 - util.py[DEBUG]: loaded blob returned None, returning default. 2022-10-11 00:44:07,148 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) 2022-10-11 00:44:07,148 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt 2022-10-11 00:44:07,148 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (,) 2022-10-11 00:44:07,148 - util.py[DEBUG]: loaded blob returned None, returning default. 2022-10-11 00:44:07,150 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource 2022-10-11 00:44:07,151 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 15462 bytes 2022-10-11 00:44:07,151 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/obj.pkl (recursive=False) 2022-10-11 00:44:07,152 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/obj.pkl (recursive=False) 2022-10-11 00:44:07,152 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource 2022-10-11 00:44:07,153 - main.py[DEBUG]: no di_report found in config. 2022-10-11 00:44:07,194 - stages.py[DEBUG]: Using distro class 2022-10-11 00:44:07,194 - stages.py[DEBUG]: Running module disk_setup () with frequency once-per-instance 2022-10-11 00:44:07,195 - handlers.py[DEBUG]: start: init-network/config-disk_setup: running config-disk_setup with frequency once-per-instance 2022-10-11 00:44:07,195 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_disk_setup - wb: [644] 23 bytes 2022-10-11 00:44:07,195 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_disk_setup (recursive=False) 2022-10-11 00:44:07,196 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_disk_setup (recursive=False) 2022-10-11 00:44:07,197 - helpers.py[DEBUG]: Running config-disk_setup using lock () 2022-10-11 00:44:07,197 - handlers.py[DEBUG]: finish: init-network/config-disk_setup: SUCCESS: config-disk_setup ran successfully 2022-10-11 00:44:07,197 - stages.py[DEBUG]: Running module migrator () with frequency always 2022-10-11 00:44:07,197 - handlers.py[DEBUG]: start: init-network/config-migrator: running config-migrator with frequency always 2022-10-11 00:44:07,197 - helpers.py[DEBUG]: Running config-migrator using lock () 2022-10-11 00:44:07,197 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names 2022-10-11 00:44:07,198 - handlers.py[DEBUG]: finish: init-network/config-migrator: SUCCESS: config-migrator ran successfully 2022-10-11 00:44:07,198 - stages.py[DEBUG]: Running module bootcmd () with frequency always 2022-10-11 00:44:07,198 - handlers.py[DEBUG]: start: init-network/config-bootcmd: running config-bootcmd with frequency always 2022-10-11 00:44:07,198 - helpers.py[DEBUG]: Running config-bootcmd using lock () 2022-10-11 00:44:07,198 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration 2022-10-11 00:44:07,198 - handlers.py[DEBUG]: finish: init-network/config-bootcmd: SUCCESS: config-bootcmd ran successfully 2022-10-11 00:44:07,198 - stages.py[DEBUG]: Running module write-files () with frequency once-per-instance 2022-10-11 00:44:07,198 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance 2022-10-11 00:44:07,199 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_write_files - wb: [644] 24 bytes 2022-10-11 00:44:07,199 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_write_files (recursive=False) 2022-10-11 00:44:07,200 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_write_files (recursive=False) 2022-10-11 00:44:07,200 - helpers.py[DEBUG]: Running config-write-files using lock () 2022-10-11 00:44:07,200 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration 2022-10-11 00:44:07,200 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files ran successfully 2022-10-11 00:44:07,200 - stages.py[DEBUG]: Running module growpart () with frequency always 2022-10-11 00:44:07,201 - handlers.py[DEBUG]: start: init-network/config-growpart: running config-growpart with frequency always 2022-10-11 00:44:07,201 - helpers.py[DEBUG]: Running config-growpart using lock () 2022-10-11 00:44:07,201 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg. Using default: {'mode': 'auto', 'devices': ['/'], 'ignore_growroot_disabled': False} 2022-10-11 00:44:07,201 - subp.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,226 - util.py[DEBUG]: Reading from /proc/878/mountinfo (quiet=False) 2022-10-11 00:44:07,226 - util.py[DEBUG]: Read 3103 bytes from /proc/878/mountinfo 2022-10-11 00:44:07,227 - util.py[DEBUG]: Reading from /sys/class/block/xvda2/partition (quiet=False) 2022-10-11 00:44:07,227 - util.py[DEBUG]: Read 2 bytes from /sys/class/block/xvda2/partition 2022-10-11 00:44:07,227 - util.py[DEBUG]: Reading from /sys/devices/vbd-768/block/xvda/dev (quiet=False) 2022-10-11 00:44:07,227 - util.py[DEBUG]: Read 6 bytes from /sys/devices/vbd-768/block/xvda/dev 2022-10-11 00:44:07,227 - subp.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/xvda', '2'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,311 - util.py[DEBUG]: resize_devices took 0.085 seconds 2022-10-11 00:44:07,311 - cc_growpart.py[DEBUG]: '/' NOCHANGE: no change necessary (/dev/xvda, 2) 2022-10-11 00:44:07,312 - handlers.py[DEBUG]: finish: init-network/config-growpart: SUCCESS: config-growpart ran successfully 2022-10-11 00:44:07,312 - stages.py[DEBUG]: Running module resizefs () with frequency always 2022-10-11 00:44:07,312 - handlers.py[DEBUG]: start: init-network/config-resizefs: running config-resizefs with frequency always 2022-10-11 00:44:07,312 - helpers.py[DEBUG]: Running config-resizefs using lock () 2022-10-11 00:44:07,327 - util.py[DEBUG]: Reading from /proc/878/mountinfo (quiet=False) 2022-10-11 00:44:07,327 - util.py[DEBUG]: Read 3103 bytes from /proc/878/mountinfo 2022-10-11 00:44:07,327 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/xvda2 mnt_point=/ path=/ 2022-10-11 00:44:07,327 - cc_resizefs.py[DEBUG]: Resizing / (xfs) using xfs_growfs / 2022-10-11 00:44:07,327 - subp.py[DEBUG]: Running command ('xfs_growfs', '/') with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,352 - util.py[DEBUG]: Resizing took 0.025 seconds 2022-10-11 00:44:07,353 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=xfs, val=True) 2022-10-11 00:44:07,353 - handlers.py[DEBUG]: finish: init-network/config-resizefs: SUCCESS: config-resizefs ran successfully 2022-10-11 00:44:07,353 - stages.py[DEBUG]: Running module set_hostname () with frequency once-per-instance 2022-10-11 00:44:07,353 - handlers.py[DEBUG]: start: init-network/config-set_hostname: running config-set_hostname with frequency once-per-instance 2022-10-11 00:44:07,354 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_set_hostname - wb: [644] 24 bytes 2022-10-11 00:44:07,354 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_set_hostname (recursive=False) 2022-10-11 00:44:07,355 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_set_hostname (recursive=False) 2022-10-11 00:44:07,356 - helpers.py[DEBUG]: Running config-set_hostname using lock () 2022-10-11 00:44:07,356 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False) 2022-10-11 00:44:07,356 - util.py[DEBUG]: Read 76 bytes from /var/lib/cloud/data/set-hostname 2022-10-11 00:44:07,356 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set-hostname 2022-10-11 00:44:07,356 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: SUCCESS: config-set_hostname ran successfully 2022-10-11 00:44:07,356 - stages.py[DEBUG]: Running module update_hostname () with frequency always 2022-10-11 00:44:07,357 - handlers.py[DEBUG]: start: init-network/config-update_hostname: running config-update_hostname with frequency always 2022-10-11 00:44:07,357 - helpers.py[DEBUG]: Running config-update_hostname using lock () 2022-10-11 00:44:07,357 - cc_update_hostname.py[DEBUG]: Updating hostname to ip-172-31-82-61.ec2.internal (ip-172-31-82-61) 2022-10-11 00:44:07,357 - subp.py[DEBUG]: Running command ['hostname'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,360 - __init__.py[DEBUG]: Attempting to update hostname to ip-172-31-82-61.ec2.internal in 1 files 2022-10-11 00:44:07,360 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-hostname - wb: [644] 28 bytes 2022-10-11 00:44:07,361 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-hostname (recursive=False) 2022-10-11 00:44:07,362 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/data/previous-hostname (recursive=False) 2022-10-11 00:44:07,362 - handlers.py[DEBUG]: finish: init-network/config-update_hostname: SUCCESS: config-update_hostname ran successfully 2022-10-11 00:44:07,362 - stages.py[DEBUG]: Running module update_etc_hosts () with frequency always 2022-10-11 00:44:07,362 - handlers.py[DEBUG]: start: init-network/config-update_etc_hosts: running config-update_etc_hosts with frequency always 2022-10-11 00:44:07,363 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock () 2022-10-11 00:44:07,363 - cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts 2022-10-11 00:44:07,363 - handlers.py[DEBUG]: finish: init-network/config-update_etc_hosts: SUCCESS: config-update_etc_hosts ran successfully 2022-10-11 00:44:07,363 - stages.py[DEBUG]: Running module rsyslog () with frequency once-per-instance 2022-10-11 00:44:07,363 - handlers.py[DEBUG]: start: init-network/config-rsyslog: running config-rsyslog with frequency once-per-instance 2022-10-11 00:44:07,363 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rsyslog - wb: [644] 24 bytes 2022-10-11 00:44:07,364 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rsyslog (recursive=False) 2022-10-11 00:44:07,364 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rsyslog (recursive=False) 2022-10-11 00:44:07,365 - helpers.py[DEBUG]: Running config-rsyslog using lock () 2022-10-11 00:44:07,365 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration 2022-10-11 00:44:07,365 - handlers.py[DEBUG]: finish: init-network/config-rsyslog: SUCCESS: config-rsyslog ran successfully 2022-10-11 00:44:07,365 - stages.py[DEBUG]: Running module users-groups () with frequency once-per-instance 2022-10-11 00:44:07,365 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance 2022-10-11 00:44:07,365 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_users_groups - wb: [644] 24 bytes 2022-10-11 00:44:07,366 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_users_groups (recursive=False) 2022-10-11 00:44:07,367 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_users_groups (recursive=False) 2022-10-11 00:44:07,367 - helpers.py[DEBUG]: Running config-users-groups using lock () 2022-10-11 00:44:07,372 - util.py[DEBUG]: Reading from /etc/os-release (quiet=True) 2022-10-11 00:44:07,372 - util.py[DEBUG]: Read 592 bytes from /etc/os-release 2022-10-11 00:44:07,373 - util.py[DEBUG]: Reading from /etc/system-image/channel.ini (quiet=True) 2022-10-11 00:44:07,373 - util.py[DEBUG]: Read 0 bytes from /etc/system-image/channel.ini 2022-10-11 00:44:07,374 - __init__.py[DEBUG]: Adding user ec2-user 2022-10-11 00:44:07,374 - subp.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['useradd', 'ec2-user', '--comment', 'Cloud User', '--groups', 'adm,systemd-journal', '--shell', '/bin/bash', '-m'] 2022-10-11 00:44:07,761 - subp.py[DEBUG]: Running command ['passwd', '-l', 'ec2-user'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:07,801 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False) 2022-10-11 00:44:07,802 - util.py[DEBUG]: Read 4328 bytes from /etc/sudoers 2022-10-11 00:44:07,803 - util.py[DEBUG]: Restoring selinux mode for /etc/sudoers.d (recursive=False) 2022-10-11 00:44:07,804 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - wb: [440] 133 bytes 2022-10-11 00:44:07,806 - util.py[DEBUG]: Restoring selinux mode for /etc/sudoers.d/90-cloud-init-users (recursive=False) 2022-10-11 00:44:07,807 - util.py[DEBUG]: Restoring selinux mode for /etc/sudoers.d/90-cloud-init-users (recursive=False) 2022-10-11 00:44:07,808 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups ran successfully 2022-10-11 00:44:07,808 - stages.py[DEBUG]: Running module ssh () with frequency once-per-instance 2022-10-11 00:44:07,808 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance 2022-10-11 00:44:07,808 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_ssh - wb: [644] 24 bytes 2022-10-11 00:44:07,809 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_ssh (recursive=False) 2022-10-11 00:44:07,810 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_ssh (recursive=False) 2022-10-11 00:44:07,810 - helpers.py[DEBUG]: Running config-ssh using lock () 2022-10-11 00:44:07,811 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key 2022-10-11 00:44:07,811 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key.pub 2022-10-11 00:44:07,811 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key 2022-10-11 00:44:07,811 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key.pub 2022-10-11 00:44:07,811 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key 2022-10-11 00:44:07,811 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key.pub 2022-10-11 00:44:07,811 - subp.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:08,192 - util.py[DEBUG]: Restoring selinux mode for /etc/ssh (recursive=True) 2022-10-11 00:44:08,194 - subp.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ecdsa', '-N', '', '-f', '/etc/ssh/ssh_host_ecdsa_key'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:08,201 - util.py[DEBUG]: Restoring selinux mode for /etc/ssh (recursive=True) 2022-10-11 00:44:08,203 - subp.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ed25519', '-N', '', '-f', '/etc/ssh/ssh_host_ed25519_key'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:08,211 - util.py[DEBUG]: Restoring selinux mode for /etc/ssh (recursive=True) 2022-10-11 00:44:08,213 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_rsa_key.pub (quiet=False) 2022-10-11 00:44:08,213 - util.py[DEBUG]: Read 587 bytes from /etc/ssh/ssh_host_rsa_key.pub 2022-10-11 00:44:08,214 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ecdsa_key.pub (quiet=False) 2022-10-11 00:44:08,214 - util.py[DEBUG]: Read 195 bytes from /etc/ssh/ssh_host_ecdsa_key.pub 2022-10-11 00:44:08,214 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ed25519_key.pub (quiet=False) 2022-10-11 00:44:08,214 - util.py[DEBUG]: Read 115 bytes from /etc/ssh/ssh_host_ed25519_key.pub 2022-10-11 00:44:08,215 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False) 2022-10-11 00:44:08,215 - util.py[DEBUG]: Read 4268 bytes from /etc/ssh/sshd_config 2022-10-11 00:44:08,216 - util.py[DEBUG]: Changing the ownership of /home/ec2-user/.ssh to 1000:1000 2022-10-11 00:44:08,217 - util.py[DEBUG]: Restoring selinux mode for /home/ec2-user/.ssh (recursive=False) 2022-10-11 00:44:08,217 - util.py[DEBUG]: Writing to /home/ec2-user/.ssh/authorized_keys - wb: [600] 0 bytes 2022-10-11 00:44:08,218 - util.py[DEBUG]: Restoring selinux mode for /home/ec2-user/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,218 - util.py[DEBUG]: Restoring selinux mode for /home/ec2-user/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,218 - util.py[DEBUG]: Changing the ownership of /home/ec2-user/.ssh/authorized_keys to 1000:1000 2022-10-11 00:44:08,219 - util.py[DEBUG]: Reading from /home/ec2-user/.ssh/authorized_keys (quiet=False) 2022-10-11 00:44:08,219 - util.py[DEBUG]: Read 0 bytes from /home/ec2-user/.ssh/authorized_keys 2022-10-11 00:44:08,219 - util.py[DEBUG]: Writing to /home/ec2-user/.ssh/authorized_keys - wb: [600] 389 bytes 2022-10-11 00:44:08,219 - util.py[DEBUG]: Restoring selinux mode for /home/ec2-user/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,219 - util.py[DEBUG]: Restoring selinux mode for /home/ec2-user/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,220 - util.py[DEBUG]: Restoring selinux mode for /home/ec2-user/.ssh (recursive=True) 2022-10-11 00:44:08,220 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False) 2022-10-11 00:44:08,220 - util.py[DEBUG]: Read 4268 bytes from /etc/ssh/sshd_config 2022-10-11 00:44:08,221 - util.py[DEBUG]: Changing the ownership of /root/.ssh to 0:0 2022-10-11 00:44:08,221 - util.py[DEBUG]: Restoring selinux mode for /root/.ssh (recursive=False) 2022-10-11 00:44:08,222 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 0 bytes 2022-10-11 00:44:08,222 - util.py[DEBUG]: Restoring selinux mode for /root/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,222 - util.py[DEBUG]: Restoring selinux mode for /root/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,222 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0 2022-10-11 00:44:08,222 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False) 2022-10-11 00:44:08,223 - util.py[DEBUG]: Read 0 bytes from /root/.ssh/authorized_keys 2022-10-11 00:44:08,223 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 555 bytes 2022-10-11 00:44:08,223 - util.py[DEBUG]: Restoring selinux mode for /root/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,223 - util.py[DEBUG]: Restoring selinux mode for /root/.ssh/authorized_keys (recursive=False) 2022-10-11 00:44:08,223 - util.py[DEBUG]: Restoring selinux mode for /root/.ssh (recursive=True) 2022-10-11 00:44:08,224 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh ran successfully 2022-10-11 00:44:08,224 - main.py[DEBUG]: Ran 12 modules with 0 failures 2022-10-11 00:44:08,224 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp6dhq3ah1) - w: [644] 518 bytes/chars 2022-10-11 00:44:08,225 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) 2022-10-11 00:44:08,225 - util.py[DEBUG]: Read 11 bytes from /proc/uptime 2022-10-11 00:44:08,225 - util.py[DEBUG]: cloud-init mode 'init' took 1.280 seconds (1.28) 2022-10-11 00:44:08,225 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources 2022-10-11 00:44:09,362 - util.py[DEBUG]: Cloud-init v. 21.1-15.el8 running 'modules:config' at Tue, 11 Oct 2022 00:44:09 +0000. Up 14.94 seconds. 2022-10-11 00:44:09,402 - stages.py[DEBUG]: Using distro class 2022-10-11 00:44:09,404 - stages.py[DEBUG]: Running module mounts () with frequency once-per-instance 2022-10-11 00:44:09,404 - handlers.py[DEBUG]: start: modules-config/config-mounts: running config-mounts with frequency once-per-instance 2022-10-11 00:44:09,404 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_mounts - wb: [644] 25 bytes 2022-10-11 00:44:09,406 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_mounts (recursive=False) 2022-10-11 00:44:09,408 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_mounts (recursive=False) 2022-10-11 00:44:09,408 - helpers.py[DEBUG]: Running config-mounts using lock () 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: mounts configuration is [] 2022-10-11 00:44:09,409 - util.py[DEBUG]: Reading from /etc/fstab (quiet=False) 2022-10-11 00:44:09,409 - util.py[DEBUG]: Read 61 bytes from /etc/fstab 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0 2022-10-11 00:44:09,409 - DataSourceEc2.py[DEBUG]: Unable to convert ephemeral0 to a device 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: changed default device ephemeral0 => None 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount ephemeral0 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: Attempting to determine the real name of swap 2022-10-11 00:44:09,409 - DataSourceEc2.py[DEBUG]: Unable to convert swap to a device 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: changed default device swap => None 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount swap 2022-10-11 00:44:09,409 - cc_mounts.py[DEBUG]: no need to setup swap 2022-10-11 00:44:09,410 - cc_mounts.py[DEBUG]: No modifications to fstab needed 2022-10-11 00:44:09,410 - handlers.py[DEBUG]: finish: modules-config/config-mounts: SUCCESS: config-mounts ran successfully 2022-10-11 00:44:09,410 - stages.py[DEBUG]: Running module locale () with frequency once-per-instance 2022-10-11 00:44:09,410 - handlers.py[DEBUG]: start: modules-config/config-locale: running config-locale with frequency once-per-instance 2022-10-11 00:44:09,410 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_locale - wb: [644] 25 bytes 2022-10-11 00:44:09,411 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_locale (recursive=False) 2022-10-11 00:44:09,411 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_locale (recursive=False) 2022-10-11 00:44:09,412 - helpers.py[DEBUG]: Running config-locale using lock () 2022-10-11 00:44:09,418 - cc_locale.py[DEBUG]: Setting locale to en_US.UTF-8 2022-10-11 00:44:09,418 - util.py[DEBUG]: Reading from /etc/locale.conf (quiet=False) 2022-10-11 00:44:09,418 - util.py[DEBUG]: Read 17 bytes from /etc/locale.conf 2022-10-11 00:44:09,418 - util.py[DEBUG]: Writing to /etc/locale.conf - wb: [644] 17 bytes 2022-10-11 00:44:09,421 - util.py[DEBUG]: Restoring selinux mode for /etc/locale.conf (recursive=False) 2022-10-11 00:44:09,423 - util.py[DEBUG]: Restoring selinux mode for /etc/locale.conf (recursive=False) 2022-10-11 00:44:09,423 - handlers.py[DEBUG]: finish: modules-config/config-locale: SUCCESS: config-locale ran successfully 2022-10-11 00:44:09,423 - stages.py[DEBUG]: Running module set-passwords () with frequency once-per-instance 2022-10-11 00:44:09,424 - handlers.py[DEBUG]: start: modules-config/config-set-passwords: running config-set-passwords with frequency once-per-instance 2022-10-11 00:44:09,424 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_set_passwords - wb: [644] 25 bytes 2022-10-11 00:44:09,424 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_set_passwords (recursive=False) 2022-10-11 00:44:09,425 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_set_passwords (recursive=False) 2022-10-11 00:44:09,425 - helpers.py[DEBUG]: Running config-set-passwords using lock () 2022-10-11 00:44:09,426 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False) 2022-10-11 00:44:09,426 - util.py[DEBUG]: Read 4268 bytes from /etc/ssh/sshd_config 2022-10-11 00:44:09,426 - ssh_util.py[DEBUG]: line 70: option PasswordAuthentication already set to no 2022-10-11 00:44:09,426 - cc_set_passwords.py[DEBUG]: No need to restart SSH service, PasswordAuthentication not updated. 2022-10-11 00:44:09,426 - handlers.py[DEBUG]: finish: modules-config/config-set-passwords: SUCCESS: config-set-passwords ran successfully 2022-10-11 00:44:09,426 - stages.py[DEBUG]: Running module rh_subscription () with frequency once-per-instance 2022-10-11 00:44:09,427 - handlers.py[DEBUG]: start: modules-config/config-rh_subscription: running config-rh_subscription with frequency once-per-instance 2022-10-11 00:44:09,427 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rh_subscription - wb: [644] 25 bytes 2022-10-11 00:44:09,427 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rh_subscription (recursive=False) 2022-10-11 00:44:09,428 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rh_subscription (recursive=False) 2022-10-11 00:44:09,428 - helpers.py[DEBUG]: Running config-rh_subscription using lock () 2022-10-11 00:44:09,428 - cc_rh_subscription.py[DEBUG]: rh_subscription: module not configured. 2022-10-11 00:44:09,428 - handlers.py[DEBUG]: finish: modules-config/config-rh_subscription: SUCCESS: config-rh_subscription ran successfully 2022-10-11 00:44:09,429 - stages.py[DEBUG]: Running module yum-add-repo () with frequency once-per-instance 2022-10-11 00:44:09,429 - handlers.py[DEBUG]: start: modules-config/config-yum-add-repo: running config-yum-add-repo with frequency once-per-instance 2022-10-11 00:44:09,429 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_yum_add_repo - wb: [644] 25 bytes 2022-10-11 00:44:09,429 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_yum_add_repo (recursive=False) 2022-10-11 00:44:09,438 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_yum_add_repo (recursive=False) 2022-10-11 00:44:09,438 - helpers.py[DEBUG]: Running config-yum-add-repo using lock () 2022-10-11 00:44:09,438 - cc_yum_add_repo.py[DEBUG]: Skipping module named yum-add-repo, no 'yum_repos' configuration found 2022-10-11 00:44:09,439 - handlers.py[DEBUG]: finish: modules-config/config-yum-add-repo: SUCCESS: config-yum-add-repo ran successfully 2022-10-11 00:44:09,439 - stages.py[DEBUG]: Running module package-update-upgrade-install () with frequency once-per-instance 2022-10-11 00:44:09,439 - handlers.py[DEBUG]: start: modules-config/config-package-update-upgrade-install: running config-package-update-upgrade-install with frequency once-per-instance 2022-10-11 00:44:09,439 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_package_update_upgrade_install - wb: [644] 25 bytes 2022-10-11 00:44:09,440 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_package_update_upgrade_install (recursive=False) 2022-10-11 00:44:09,440 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_package_update_upgrade_install (recursive=False) 2022-10-11 00:44:09,441 - helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock () 2022-10-11 00:44:09,441 - handlers.py[DEBUG]: finish: modules-config/config-package-update-upgrade-install: SUCCESS: config-package-update-upgrade-install ran successfully 2022-10-11 00:44:09,441 - stages.py[DEBUG]: Running module timezone () with frequency once-per-instance 2022-10-11 00:44:09,443 - handlers.py[DEBUG]: start: modules-config/config-timezone: running config-timezone with frequency once-per-instance 2022-10-11 00:44:09,443 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_timezone - wb: [644] 25 bytes 2022-10-11 00:44:09,443 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_timezone (recursive=False) 2022-10-11 00:44:09,444 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_timezone (recursive=False) 2022-10-11 00:44:09,445 - helpers.py[DEBUG]: Running config-timezone using lock () 2022-10-11 00:44:09,445 - cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified 2022-10-11 00:44:09,445 - handlers.py[DEBUG]: finish: modules-config/config-timezone: SUCCESS: config-timezone ran successfully 2022-10-11 00:44:09,445 - stages.py[DEBUG]: Running module puppet () with frequency once-per-instance 2022-10-11 00:44:09,445 - handlers.py[DEBUG]: start: modules-config/config-puppet: running config-puppet with frequency once-per-instance 2022-10-11 00:44:09,445 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_puppet - wb: [644] 25 bytes 2022-10-11 00:44:09,446 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_puppet (recursive=False) 2022-10-11 00:44:09,446 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_puppet (recursive=False) 2022-10-11 00:44:09,447 - helpers.py[DEBUG]: Running config-puppet using lock () 2022-10-11 00:44:09,447 - cc_puppet.py[DEBUG]: Skipping module named puppet, no 'puppet' configuration found 2022-10-11 00:44:09,447 - handlers.py[DEBUG]: finish: modules-config/config-puppet: SUCCESS: config-puppet ran successfully 2022-10-11 00:44:09,447 - stages.py[DEBUG]: Running module chef () with frequency always 2022-10-11 00:44:09,447 - handlers.py[DEBUG]: start: modules-config/config-chef: running config-chef with frequency always 2022-10-11 00:44:09,447 - helpers.py[DEBUG]: Running config-chef using lock () 2022-10-11 00:44:09,447 - cc_chef.py[DEBUG]: Skipping module named chef, no 'chef' key in configuration 2022-10-11 00:44:09,447 - handlers.py[DEBUG]: finish: modules-config/config-chef: SUCCESS: config-chef ran successfully 2022-10-11 00:44:09,447 - stages.py[DEBUG]: Running module salt-minion () with frequency once-per-instance 2022-10-11 00:44:09,448 - handlers.py[DEBUG]: start: modules-config/config-salt-minion: running config-salt-minion with frequency once-per-instance 2022-10-11 00:44:09,448 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_salt_minion - wb: [644] 24 bytes 2022-10-11 00:44:09,448 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_salt_minion (recursive=False) 2022-10-11 00:44:09,449 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_salt_minion (recursive=False) 2022-10-11 00:44:09,449 - helpers.py[DEBUG]: Running config-salt-minion using lock () 2022-10-11 00:44:09,450 - cc_salt_minion.py[DEBUG]: Skipping module named salt-minion, no 'salt_minion' key in configuration 2022-10-11 00:44:09,450 - handlers.py[DEBUG]: finish: modules-config/config-salt-minion: SUCCESS: config-salt-minion ran successfully 2022-10-11 00:44:09,450 - stages.py[DEBUG]: Running module mcollective () with frequency once-per-instance 2022-10-11 00:44:09,450 - handlers.py[DEBUG]: start: modules-config/config-mcollective: running config-mcollective with frequency once-per-instance 2022-10-11 00:44:09,450 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_mcollective - wb: [644] 25 bytes 2022-10-11 00:44:09,451 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_mcollective (recursive=False) 2022-10-11 00:44:09,451 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_mcollective (recursive=False) 2022-10-11 00:44:09,452 - helpers.py[DEBUG]: Running config-mcollective using lock () 2022-10-11 00:44:09,452 - cc_mcollective.py[DEBUG]: Skipping module named mcollective, no 'mcollective' key in configuration 2022-10-11 00:44:09,452 - handlers.py[DEBUG]: finish: modules-config/config-mcollective: SUCCESS: config-mcollective ran successfully 2022-10-11 00:44:09,452 - stages.py[DEBUG]: Running module disable-ec2-metadata () with frequency always 2022-10-11 00:44:09,452 - handlers.py[DEBUG]: start: modules-config/config-disable-ec2-metadata: running config-disable-ec2-metadata with frequency always 2022-10-11 00:44:09,452 - helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock () 2022-10-11 00:44:09,452 - cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled 2022-10-11 00:44:09,452 - handlers.py[DEBUG]: finish: modules-config/config-disable-ec2-metadata: SUCCESS: config-disable-ec2-metadata ran successfully 2022-10-11 00:44:09,452 - stages.py[DEBUG]: Running module runcmd () with frequency once-per-instance 2022-10-11 00:44:09,453 - handlers.py[DEBUG]: start: modules-config/config-runcmd: running config-runcmd with frequency once-per-instance 2022-10-11 00:44:09,453 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_runcmd - wb: [644] 24 bytes 2022-10-11 00:44:09,456 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_runcmd (recursive=False) 2022-10-11 00:44:09,456 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_runcmd (recursive=False) 2022-10-11 00:44:09,457 - helpers.py[DEBUG]: Running config-runcmd using lock () 2022-10-11 00:44:09,457 - cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration 2022-10-11 00:44:09,457 - handlers.py[DEBUG]: finish: modules-config/config-runcmd: SUCCESS: config-runcmd ran successfully 2022-10-11 00:44:09,457 - main.py[DEBUG]: Ran 13 modules with 0 failures 2022-10-11 00:44:09,457 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpnv8_tt5_) - w: [644] 546 bytes/chars 2022-10-11 00:44:09,458 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) 2022-10-11 00:44:09,458 - util.py[DEBUG]: Read 11 bytes from /proc/uptime 2022-10-11 00:44:09,458 - util.py[DEBUG]: cloud-init mode 'modules' took 0.226 seconds (0.23) 2022-10-11 00:44:09,458 - handlers.py[DEBUG]: finish: modules-config: SUCCESS: running modules for config 2022-10-11 00:44:10,189 - util.py[DEBUG]: Cloud-init v. 21.1-15.el8 running 'modules:final' at Tue, 11 Oct 2022 00:44:10 +0000. Up 15.77 seconds. 2022-10-11 00:44:10,251 - stages.py[DEBUG]: Using distro class 2022-10-11 00:44:10,252 - stages.py[DEBUG]: Running module rightscale_userdata () with frequency once-per-instance 2022-10-11 00:44:10,252 - handlers.py[DEBUG]: start: modules-final/config-rightscale_userdata: running config-rightscale_userdata with frequency once-per-instance 2022-10-11 00:44:10,252 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rightscale_userdata - wb: [644] 25 bytes 2022-10-11 00:44:10,254 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rightscale_userdata (recursive=False) 2022-10-11 00:44:10,256 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_rightscale_userdata (recursive=False) 2022-10-11 00:44:10,257 - helpers.py[DEBUG]: Running config-rightscale_userdata using lock () 2022-10-11 00:44:10,257 - cc_rightscale_userdata.py[DEBUG]: Failed to get raw userdata in module rightscale_userdata 2022-10-11 00:44:10,257 - handlers.py[DEBUG]: finish: modules-final/config-rightscale_userdata: SUCCESS: config-rightscale_userdata ran successfully 2022-10-11 00:44:10,257 - stages.py[DEBUG]: Running module scripts-per-once () with frequency once 2022-10-11 00:44:10,257 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once 2022-10-11 00:44:10,257 - util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [644] 25 bytes 2022-10-11 00:44:10,258 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/sem/config_scripts_per_once.once (recursive=False) 2022-10-11 00:44:10,258 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/sem/config_scripts_per_once.once (recursive=False) 2022-10-11 00:44:10,259 - helpers.py[DEBUG]: Running config-scripts-per-once using lock () 2022-10-11 00:44:10,259 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once ran successfully 2022-10-11 00:44:10,259 - stages.py[DEBUG]: Running module scripts-per-boot () with frequency always 2022-10-11 00:44:10,259 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always 2022-10-11 00:44:10,259 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock () 2022-10-11 00:44:10,259 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully 2022-10-11 00:44:10,259 - stages.py[DEBUG]: Running module scripts-per-instance () with frequency once-per-instance 2022-10-11 00:44:10,260 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance 2022-10-11 00:44:10,260 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_scripts_per_instance - wb: [644] 25 bytes 2022-10-11 00:44:10,260 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_scripts_per_instance (recursive=False) 2022-10-11 00:44:10,268 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_scripts_per_instance (recursive=False) 2022-10-11 00:44:10,268 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock () 2022-10-11 00:44:10,268 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance ran successfully 2022-10-11 00:44:10,268 - stages.py[DEBUG]: Running module scripts-user () with frequency once-per-instance 2022-10-11 00:44:10,269 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance 2022-10-11 00:44:10,269 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_scripts_user - wb: [644] 24 bytes 2022-10-11 00:44:10,269 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_scripts_user (recursive=False) 2022-10-11 00:44:10,270 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_scripts_user (recursive=False) 2022-10-11 00:44:10,271 - helpers.py[DEBUG]: Running config-scripts-user using lock () 2022-10-11 00:44:10,271 - subp.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts/common.sh'] with allowed return codes [0] (shell=False, capture=False) 2022-10-11 00:44:10,282 - subp.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts/configure.sh'] with allowed return codes [0] (shell=False, capture=False) 2022-10-11 00:44:10,284 - subp.py[DEBUG]: Exec format error. Missing #! in script? Command: ['/var/lib/cloud/instance/scripts/configure.sh'] Exit code: - Reason: [Errno 8] Exec format error: b'/var/lib/cloud/instance/scripts/configure.sh' Stdout: - Stderr: - 2022-10-11 00:44:10,284 - cc_scripts_user.py[WARNING]: Failed to run module scripts-user (scripts in /var/lib/cloud/instance/scripts) 2022-10-11 00:44:10,284 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: FAIL: running config-scripts-user with frequency once-per-instance 2022-10-11 00:44:10,284 - util.py[WARNING]: Running module scripts-user () failed 2022-10-11 00:44:10,284 - util.py[DEBUG]: Running module scripts-user () failed Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/cloudinit/stages.py", line 876, in _run_modules freq=freq) File "/usr/lib/python3.6/site-packages/cloudinit/cloud.py", line 54, in run return self._runners.run(name, functor, args, freq, clear_on_fail) File "/usr/lib/python3.6/site-packages/cloudinit/helpers.py", line 185, in run results = functor(*args) File "/usr/lib/python3.6/site-packages/cloudinit/config/cc_scripts_user.py", line 45, in handle subp.runparts(runparts_path) File "/usr/lib/python3.6/site-packages/cloudinit/subp.py", line 386, in runparts (len(failed), ",".join(failed), len(attempted))) RuntimeError: Runparts: 1 failures (configure.sh) in 2 attempted commands 2022-10-11 00:44:10,335 - stages.py[DEBUG]: Running module ssh-authkey-fingerprints () with frequency once-per-instance 2022-10-11 00:44:10,335 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance 2022-10-11 00:44:10,335 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_ssh_authkey_fingerprints - wb: [644] 24 bytes 2022-10-11 00:44:10,336 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_ssh_authkey_fingerprints (recursive=False) 2022-10-11 00:44:10,337 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_ssh_authkey_fingerprints (recursive=False) 2022-10-11 00:44:10,338 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock () 2022-10-11 00:44:10,339 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False) 2022-10-11 00:44:10,339 - util.py[DEBUG]: Read 4268 bytes from /etc/ssh/sshd_config 2022-10-11 00:44:10,340 - util.py[DEBUG]: Restoring selinux mode for /home/ec2-user/.ssh (recursive=True) 2022-10-11 00:44:10,341 - util.py[DEBUG]: Reading from /home/ec2-user/.ssh/authorized_keys (quiet=False) 2022-10-11 00:44:10,342 - util.py[DEBUG]: Read 389 bytes from /home/ec2-user/.ssh/authorized_keys 2022-10-11 00:44:10,348 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully 2022-10-11 00:44:10,348 - stages.py[DEBUG]: Running module keys-to-console () with frequency once-per-instance 2022-10-11 00:44:10,348 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance 2022-10-11 00:44:10,348 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_keys_to_console - wb: [644] 25 bytes 2022-10-11 00:44:10,349 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_keys_to_console (recursive=False) 2022-10-11 00:44:10,350 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_keys_to_console (recursive=False) 2022-10-11 00:44:10,350 - helpers.py[DEBUG]: Running config-keys-to-console using lock () 2022-10-11 00:44:10,350 - subp.py[DEBUG]: Running command ['/usr/libexec/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True) 2022-10-11 00:44:10,414 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully 2022-10-11 00:44:10,414 - stages.py[DEBUG]: Running module phone-home () with frequency once-per-instance 2022-10-11 00:44:10,414 - handlers.py[DEBUG]: start: modules-final/config-phone-home: running config-phone-home with frequency once-per-instance 2022-10-11 00:44:10,415 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_phone_home - wb: [644] 25 bytes 2022-10-11 00:44:10,416 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_phone_home (recursive=False) 2022-10-11 00:44:10,417 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_phone_home (recursive=False) 2022-10-11 00:44:10,417 - helpers.py[DEBUG]: Running config-phone-home using lock () 2022-10-11 00:44:10,417 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found 2022-10-11 00:44:10,417 - handlers.py[DEBUG]: finish: modules-final/config-phone-home: SUCCESS: config-phone-home ran successfully 2022-10-11 00:44:10,417 - stages.py[DEBUG]: Running module final-message () with frequency always 2022-10-11 00:44:10,418 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always 2022-10-11 00:44:10,418 - helpers.py[DEBUG]: Running config-final-message using lock () 2022-10-11 00:44:10,418 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) 2022-10-11 00:44:10,418 - util.py[DEBUG]: Read 11 bytes from /proc/uptime 2022-10-11 00:44:10,422 - util.py[DEBUG]: Cloud-init v. 21.1-15.el8 finished at Tue, 11 Oct 2022 00:44:10 +0000. Datasource DataSourceEc2Local. Up 16.08 seconds 2022-10-11 00:44:10,423 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 57 bytes 2022-10-11 00:44:10,423 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/boot-finished (recursive=False) 2022-10-11 00:44:10,424 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/boot-finished (recursive=False) 2022-10-11 00:44:10,434 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully 2022-10-11 00:44:10,434 - stages.py[DEBUG]: Running module power-state-change () with frequency once-per-instance 2022-10-11 00:44:10,434 - handlers.py[DEBUG]: start: modules-final/config-power-state-change: running config-power-state-change with frequency once-per-instance 2022-10-11 00:44:10,434 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_power_state_change - wb: [644] 25 bytes 2022-10-11 00:44:10,435 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_power_state_change (recursive=False) 2022-10-11 00:44:10,435 - util.py[DEBUG]: Restoring selinux mode for /var/lib/cloud/instances/i-024f3ce3512b468d1/sem/config_power_state_change (recursive=False) 2022-10-11 00:44:10,436 - helpers.py[DEBUG]: Running config-power-state-change using lock () 2022-10-11 00:44:10,436 - cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing 2022-10-11 00:44:10,436 - handlers.py[DEBUG]: finish: modules-final/config-power-state-change: SUCCESS: config-power-state-change ran successfully 2022-10-11 00:44:10,436 - main.py[DEBUG]: Ran 10 modules with 1 failures 2022-10-11 00:44:10,437 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpi5e3klyw) - w: [644] 679 bytes/chars 2022-10-11 00:44:10,437 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmpkq0gnali) - w: [644] 172 bytes/chars 2022-10-11 00:44:10,437 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json' 2022-10-11 00:44:10,437 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False) 2022-10-11 00:44:10,437 - util.py[DEBUG]: Read 11 bytes from /proc/uptime 2022-10-11 00:44:10,437 - util.py[DEBUG]: cloud-init mode 'modules' took 0.358 seconds (0.36) 2022-10-11 00:44:10,437 - handlers.py[DEBUG]: finish: modules-final: FAIL: running modules for final