2022-04-12 10:18:42,439 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'init-local' at Tue, 12 Apr 2022 17:18:41 PST. Up 12.349832058 seconds.
2022-04-12 10:18:42,450 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2022-04-12 10:18:42,452 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2022-04-12 10:18:42,454 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/instance/boot-finished
2022-04-12 10:18:42,454 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/instance
2022-04-12 10:18:42,454 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/data/no-net
2022-04-12 10:18:42,455 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-04-12 10:18:42,458 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-04-12 10:18:42,459 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-04-12 10:18:42,515 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-04-12 10:18:42,515 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-04-12 10:18:42,515 - __init__.py[DEBUG]: Looking for for data source in: ['ConfigDrive'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2022-04-12 10:18:42,516 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2022-04-12 10:18:42,516 - importer.py[DEBUG]: Failed at attempted import of 'DataSourceConfigDrive' due to: No module named DataSourceConfigDrive
2022-04-12 10:18:42,568 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2022-04-12 10:18:42,568 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceConfigDrive']
2022-04-12 10:18:42,569 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDrive'>
2022-04-12 10:18:42,569 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd0'] with allowed return codes [0] (shell=False, capture=True)
2022-04-12 10:18:42,588 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd1'] with allowed return codes [0] (shell=False, capture=True)
2022-04-12 10:18:42,605 - cloud-init[DEBUG]: No local datasource found
2022-04-12 10:18:42,622 - util.py[DEBUG]: cloud-init mode 'init' took 1.358 seconds (1.31)
2022-04-12 10:18:43,380 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'init' at Tue, 12 Apr 2022 17:18:43 PST. Up 14.2502770424 seconds.
2022-04-12 10:18:43,392 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2022-04-12 10:18:43,393 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2022-04-12 10:18:43,394 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True)
2022-04-12 10:18:43,411 - util.py[DEBUG]: Running command ['netstat', '-rn'] with allowed return codes [0] (shell=False, capture=True)
2022-04-12 10:18:43,453 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-04-12 10:18:43,465 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-04-12 10:18:43,477 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-04-12 10:18:43,488 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-04-12 10:18:43,500 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-04-12 10:18:43,512 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-04-12 10:18:43,523 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-04-12 10:18:43,541 - cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2022-04-12 10:18:43,542 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/data/no-net (quiet=False)
2022-04-12 10:18:43,542 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-04-12 10:18:43,543 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-04-12 10:18:43,547 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-04-12 10:18:43,547 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-04-12 10:18:43,581 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-04-12 10:18:43,582 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-04-12 10:18:43,582 - __init__.py[DEBUG]: Looking for for data source in: ['ConfigDrive'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK']
2022-04-12 10:18:43,582 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2022-04-12 10:18:43,583 - importer.py[DEBUG]: Failed at attempted import of 'DataSourceConfigDrive' due to: No module named DataSourceConfigDrive
2022-04-12 10:18:43,585 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2022-04-12 10:18:43,586 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceConfigDriveNet']
2022-04-12 10:18:43,586 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDriveNet'>
2022-04-12 10:18:43,586 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd0'] with allowed return codes [0] (shell=False, capture=True)
2022-04-12 10:18:43,604 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd1'] with allowed return codes [0] (shell=False, capture=True)
2022-04-12 10:18:43,620 - util.py[WARNING]: No instance datasource found! Likely bad things to come!
2022-04-12 10:18:43,621 - util.py[DEBUG]: No instance datasource found! Likely bad things to come!
Traceback (most recent call last):
File "/opt/freeware/bin/cloud-init", line 242, in main_init
init.fetch()
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/stages.py", line 308, in fetch
return self._get_data_source()
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/stages.py", line 236, in _get_data_source
pkg_list)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/sources/__init__.py", line 263, in find_source
raise DataSourceNotFoundException(msg)
DataSourceNotFoundException: Did not find any data source, searched classes: (DataSourceConfigDriveNet)
2022-04-12 10:18:43,640 - util.py[DEBUG]: cloud-init mode 'init' took 0.418 seconds (0.42)
2022-05-03 06:22:37,794 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'init-local' at Tue, 03 May 2022 13:22:37 PST. Up 20.6380639076 seconds.
2022-05-03 06:22:37,815 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2022-05-03 06:22:37,817 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2022-05-03 06:22:37,819 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/instance/boot-finished
2022-05-03 06:22:37,820 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/instance
2022-05-03 06:22:37,820 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/data/no-net
2022-05-03 06:22:37,820 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-05-03 06:22:37,824 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-03 06:22:37,825 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-03 06:22:37,928 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-03 06:22:37,929 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-03 06:22:37,929 - __init__.py[DEBUG]: Looking for for data source in: ['ConfigDrive'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2022-05-03 06:22:37,929 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2022-05-03 06:22:37,930 - importer.py[DEBUG]: Failed at attempted import of 'DataSourceConfigDrive' due to: No module named DataSourceConfigDrive
2022-05-03 06:22:37,957 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2022-05-03 06:22:37,958 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceConfigDrive']
2022-05-03 06:22:37,958 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDrive'>
2022-05-03 06:22:37,959 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd0'] with allowed return codes [0] (shell=False, capture=True)
2022-05-03 06:22:37,980 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd1'] with allowed return codes [0] (shell=False, capture=True)
2022-05-03 06:22:37,999 - cloud-init[DEBUG]: No local datasource found
2022-05-03 06:22:38,018 - util.py[DEBUG]: cloud-init mode 'init' took 0.552 seconds (0.46)
2022-05-03 06:22:38,817 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'init' at Tue, 03 May 2022 13:22:38 PST. Up 21.684926033 seconds.
2022-05-03 06:22:38,830 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2022-05-03 06:22:38,832 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2022-05-03 06:22:38,833 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True)
2022-05-03 06:22:38,853 - util.py[DEBUG]: Running command ['netstat', '-rn'] with allowed return codes [0] (shell=False, capture=True)
2022-05-03 06:22:38,878 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-03 06:22:38,892 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-03 06:22:38,905 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-03 06:22:38,918 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-03 06:22:38,931 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-03 06:22:38,944 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-03 06:22:38,958 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-03 06:22:38,978 - cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2022-05-03 06:22:38,979 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/data/no-net (quiet=False)
2022-05-03 06:22:38,979 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-05-03 06:22:38,980 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-05-03 06:22:38,984 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-03 06:22:38,984 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-03 06:22:39,020 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-03 06:22:39,020 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-03 06:22:39,021 - __init__.py[DEBUG]: Looking for for data source in: ['ConfigDrive'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK']
2022-05-03 06:22:39,021 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2022-05-03 06:22:39,022 - importer.py[DEBUG]: Failed at attempted import of 'DataSourceConfigDrive' due to: No module named DataSourceConfigDrive
2022-05-03 06:22:39,025 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2022-05-03 06:22:39,025 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceConfigDriveNet']
2022-05-03 06:22:39,025 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDriveNet'>
2022-05-03 06:22:39,026 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd0'] with allowed return codes [0] (shell=False, capture=True)
2022-05-03 06:22:39,046 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd1'] with allowed return codes [0] (shell=False, capture=True)
2022-05-03 06:22:39,066 - util.py[WARNING]: No instance datasource found! Likely bad things to come!
2022-05-03 06:22:39,066 - util.py[DEBUG]: No instance datasource found! Likely bad things to come!
Traceback (most recent call last):
File "/opt/freeware/bin/cloud-init", line 242, in main_init
init.fetch()
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/stages.py", line 308, in fetch
return self._get_data_source()
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/stages.py", line 236, in _get_data_source
pkg_list)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/sources/__init__.py", line 263, in find_source
raise DataSourceNotFoundException(msg)
DataSourceNotFoundException: Did not find any data source, searched classes: (DataSourceConfigDriveNet)
2022-05-03 06:22:39,087 - util.py[DEBUG]: cloud-init mode 'init' took 0.431 seconds (0.43)
2022-05-11 03:18:41,077 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'init-local' at Wed, 11 May 2022 10:18:40 PST. Up 9.95441699028 seconds.
2022-05-11 03:18:41,088 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2022-05-11 03:18:41,089 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2022-05-11 03:18:41,091 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/instance/boot-finished
2022-05-11 03:18:41,091 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/instance
2022-05-11 03:18:41,091 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/data/no-net
2022-05-11 03:18:41,092 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-05-11 03:18:41,095 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-11 03:18:41,095 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-11 03:18:41,136 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-11 03:18:41,136 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-11 03:18:41,137 - __init__.py[DEBUG]: Looking for for data source in: ['ConfigDrive'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2022-05-11 03:18:41,137 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2022-05-11 03:18:41,138 - importer.py[DEBUG]: Failed at attempted import of 'DataSourceConfigDrive' due to: No module named DataSourceConfigDrive
2022-05-11 03:18:41,145 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2022-05-11 03:18:41,145 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceConfigDrive']
2022-05-11 03:18:41,145 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDrive'>
2022-05-11 03:18:41,146 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd0'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:41,166 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd1'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:41,183 - util.py[DEBUG]: Running command /usr/sbin/mount with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:41,208 - util.py[DEBUG]: Running command ['/usr/sbin/mount', '-o', 'ro,sync', '-vcdrfs', '/dev/cd0', '/tmp/tmplb2Eq3'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:41,228 - util.py[DEBUG]: Reading from /tmp/tmplb2Eq3/openstack/2012-08-10/meta_data.json (quiet=False)
2022-05-11 03:18:41,229 - util.py[DEBUG]: Read 350 bytes from /tmp/tmplb2Eq3/openstack/2012-08-10/meta_data.json
2022-05-11 03:18:41,229 - util.py[DEBUG]: Reading from /tmp/tmplb2Eq3/openstack/content/0000 (quiet=False)
2022-05-11 03:18:41,230 - util.py[DEBUG]: Read 643 bytes from /tmp/tmplb2Eq3/openstack/content/0000
2022-05-11 03:18:41,232 - util.py[DEBUG]: Reading from /tmp/tmplb2Eq3/ec2/latest/meta-data.json (quiet=False)
2022-05-11 03:18:41,232 - util.py[DEBUG]: Read 595 bytes from /tmp/tmplb2Eq3/ec2/latest/meta-data.json
2022-05-11 03:18:41,233 - util.py[DEBUG]: Running command ['/usr/sbin/umount', '/tmp/tmplb2Eq3'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:41,244 - util.py[DEBUG]: Recursively deleting /tmp/tmplb2Eq3
2022-05-11 03:18:41,245 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:41,245 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:41,246 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:41,246 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:41,246 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:41,246 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:41,247 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:41,247 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:41,247 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:41,247 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:41,248 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:41,248 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:41,248 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:41,248 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:41,249 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:41,249 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:41,249 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/data/instance-id (quiet=False)
2022-05-11 03:18:41,251 - util.py[DEBUG]: Read 37 bytes from /opt/freeware/var/lib/cloud/data/instance-id
2022-05-11 03:18:41,252 - DataSourceConfigDrive.py[DEBUG]: Updating network interfaces from config drive
2022-05-11 03:18:41,252 - util.py[DEBUG]: Attempting to remove /etc/resolv.conf
2022-05-11 03:18:41,253 - util.py[DEBUG]: Running command ['/usr/sbin/chrctcp', '-S', '-d', 'dhcpcd'] with allowed return codes [0] (shell=False, capture=False)
2022-05-11 03:18:41,272 - util.py[DEBUG]: Running command ['/usr/sbin/chrctcp', '-S', '-d', 'ndpd-host'] with allowed return codes [0] (shell=False, capture=False)
2022-05-11 03:18:41,289 - util.py[DEBUG]: Running command ['/usr/sbin/chrctcp', '-d', 'autoconf6'] with allowed return codes [0] (shell=False, capture=False)
2022-05-11 03:18:41,302 - util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['/usr/sbin/chdev', '-l', 'en0', '-anetmask=255.255.255.128', '-anetaddr=172.26.103.221']
2022-05-11 03:18:43,362 - util.py[DEBUG]: Running command ['/etc/ifconfig', 'en0', 'down', 'detach'] with allowed return codes [0, 1] (shell=False, capture=False)
2022-05-11 03:18:45,687 - util.py[DEBUG]: Running command ['/usr/sbin/chdev', '-l', 'ent0', '-ajumbo_frames=yes'] with allowed return codes [0, 1] (shell=False, capture=False)
2022-05-11 03:18:47,703 - util.py[DEBUG]: Running command ['/usr/sbin/chdev', '-l', 'en0', '-amtu=1500'] with allowed return codes [0, 1] (shell=False, capture=False)
2022-05-11 03:18:49,754 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'inet0', '-a', 'route', '-F', 'value'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:50,766 - util.py[DEBUG]: Running command ['/usr/sbin/chdev', '-l', 'inet0', '-aroute=net,-hopcount,0,,0,172.26.103.129'] with allowed return codes [0, 1] (shell=False, capture=False)
2022-05-11 03:18:52,808 - util.py[DEBUG]: Reading from /etc/resolv.conf (quiet=False)
2022-05-11 03:18:52,809 - aix_util.py[INFO]: Failed at parsing /etc/resolv.conf creating an empty instance
2022-05-11 03:18:52,809 - util.py[DEBUG]: Writing to /etc/resolv.conf - wb: [420] 40 bytes
2022-05-11 03:18:52,811 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'state', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:53,824 - aix.py[DEBUG]: Attempting to run bring up interface eth0 using command ['/usr/sbin/chdev', '-l', 'en0', '-a', 'state=up']
2022-05-11 03:18:53,824 - util.py[DEBUG]: Running command ['/usr/sbin/chdev', '-l', 'en0', '-a', 'state=up'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:54,880 - DataSourceConfigDrive.py[DEBUG]: DataSourceConfigDrive [local,ver=None][source=None]: not claiming datasource, dsmode=net
2022-05-11 03:18:54,881 - cloud-init[DEBUG]: No local datasource found
2022-05-11 03:18:54,898 - util.py[DEBUG]: cloud-init mode 'init' took 13.991 seconds (13.98)
2022-05-11 03:18:55,624 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'init' at Wed, 11 May 2022 10:18:55 PST. Up 24.509141922 seconds.
2022-05-11 03:18:55,635 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2022-05-11 03:18:55,636 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2022-05-11 03:18:55,637 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:55,653 - util.py[DEBUG]: Running command ['netstat', '-rn'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:55,692 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:55,704 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:55,716 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:55,727 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:55,739 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:55,750 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'en0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:55,762 - util.py[DEBUG]: Running command ['/usr/sbin/lsattr', '-El', 'lo0', '-a', 'netmask', '-F', 'value'] with allowed return codes [0, 255] (shell=False, capture=True)
2022-05-11 03:18:55,780 - cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2022-05-11 03:18:55,781 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/data/no-net (quiet=False)
2022-05-11 03:18:55,781 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-05-11 03:18:55,782 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/obj.pkl (quiet=False)
2022-05-11 03:18:55,785 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-11 03:18:55,786 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-11 03:18:55,819 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-11 03:18:55,819 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-11 03:18:55,820 - __init__.py[DEBUG]: Looking for for data source in: ['ConfigDrive'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK']
2022-05-11 03:18:55,820 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2022-05-11 03:18:55,821 - importer.py[DEBUG]: Failed at attempted import of 'DataSourceConfigDrive' due to: No module named DataSourceConfigDrive
2022-05-11 03:18:55,824 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2022-05-11 03:18:55,824 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceConfigDriveNet']
2022-05-11 03:18:55,824 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDriveNet'>
2022-05-11 03:18:55,825 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd0'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:55,842 - util.py[DEBUG]: Running command ['/usr/sbin/lsdev', '-Cl', 'cd1'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:55,859 - util.py[DEBUG]: Running command /usr/sbin/mount with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:55,884 - util.py[DEBUG]: Running command ['/usr/sbin/mount', '-o', 'ro,sync', '-vcdrfs', '/dev/cd0', '/tmp/tmpAcx2kl'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:55,901 - util.py[DEBUG]: Reading from /tmp/tmpAcx2kl/openstack/2012-08-10/meta_data.json (quiet=False)
2022-05-11 03:18:55,902 - util.py[DEBUG]: Read 350 bytes from /tmp/tmpAcx2kl/openstack/2012-08-10/meta_data.json
2022-05-11 03:18:55,903 - util.py[DEBUG]: Reading from /tmp/tmpAcx2kl/openstack/content/0000 (quiet=False)
2022-05-11 03:18:55,904 - util.py[DEBUG]: Read 643 bytes from /tmp/tmpAcx2kl/openstack/content/0000
2022-05-11 03:18:55,905 - util.py[DEBUG]: Reading from /tmp/tmpAcx2kl/ec2/latest/meta-data.json (quiet=False)
2022-05-11 03:18:55,905 - util.py[DEBUG]: Read 595 bytes from /tmp/tmpAcx2kl/ec2/latest/meta-data.json
2022-05-11 03:18:55,906 - util.py[DEBUG]: Running command ['/usr/sbin/umount', '/tmp/tmpAcx2kl'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:18:55,917 - util.py[DEBUG]: Recursively deleting /tmp/tmpAcx2kl
2022-05-11 03:18:55,918 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,918 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,919 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,919 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,919 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,919 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,920 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,920 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,920 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,920 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,921 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,921 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,921 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,922 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,922 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,922 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,922 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/data/instance-id (quiet=False)
2022-05-11 03:18:55,923 - util.py[DEBUG]: Read 37 bytes from /opt/freeware/var/lib/cloud/data/instance-id
2022-05-11 03:18:55,923 - stages.py[INFO]: Loaded datasource DataSourceConfigDriveNet - DataSourceConfigDriveNet [net,ver=2][source=cd0]
2022-05-11 03:18:55,924 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2022-05-11 03:18:55,924 - util.py[DEBUG]: Reading from /opt/freeware/etc/cloud/cloud.cfg (quiet=False)
2022-05-11 03:18:55,924 - util.py[DEBUG]: Read 2430 bytes from /opt/freeware/etc/cloud/cloud.cfg
2022-05-11 03:18:55,925 - util.py[DEBUG]: Attempting to load yaml from string of length 2430 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:55,964 - util.py[DEBUG]: Reading from /opt/freeware/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2022-05-11 03:18:55,964 - util.py[DEBUG]: Read 1908 bytes from /opt/freeware/etc/cloud/cloud.cfg.d/05_logging.cfg
2022-05-11 03:18:55,965 - util.py[DEBUG]: Attempting to load yaml from string of length 1908 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:55,982 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,982 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,982 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,982 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,983 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,983 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,983 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,983 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,984 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,984 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,984 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,984 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,984 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,985 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,985 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,985 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,985 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,986 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,986 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,986 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,986 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,986 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,987 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,987 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,987 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,987 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,988 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,988 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,988 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,988 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,988 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,989 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,989 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,989 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,989 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,990 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,990 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,990 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,990 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,990 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,991 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,991 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,991 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,991 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,992 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:55,992 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:55,992 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:55,992 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:55,993 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:55,993 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:55,993 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:55,993 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:55,994 - util.py[DEBUG]: Attempting to remove /opt/freeware/var/lib/cloud/instance
2022-05-11 03:18:55,995 - util.py[DEBUG]: Creating symbolic link from '/opt/freeware/var/lib/cloud/instance' => '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4'
2022-05-11 03:18:56,004 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/datasource (quiet=False)
2022-05-11 03:18:56,004 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/datasource - wb: [420] 75 bytes
2022-05-11 03:18:56,005 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/data/previous-datasource - wb: [420] 75 bytes
2022-05-11 03:18:56,007 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/data/instance-id (quiet=False)
2022-05-11 03:18:56,007 - util.py[DEBUG]: Read 37 bytes from /opt/freeware/var/lib/cloud/data/instance-id
2022-05-11 03:18:56,007 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/data/instance-id - wb: [420] 37 bytes
2022-05-11 03:18:56,009 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/data/previous-instance-id - wb: [420] 37 bytes
2022-05-11 03:18:56,011 - cloud-init[DEBUG]: init will now be targeting instance id: 592808f8-1eb2-45a8-ade2-78896b45dad4
2022-05-11 03:18:56,011 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2022-05-11 03:18:56,011 - util.py[DEBUG]: Reading from /opt/freeware/etc/cloud/cloud.cfg (quiet=False)
2022-05-11 03:18:56,012 - util.py[DEBUG]: Read 2430 bytes from /opt/freeware/etc/cloud/cloud.cfg
2022-05-11 03:18:56,012 - util.py[DEBUG]: Attempting to load yaml from string of length 2430 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:56,050 - util.py[DEBUG]: Reading from /opt/freeware/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2022-05-11 03:18:56,050 - util.py[DEBUG]: Read 1908 bytes from /opt/freeware/etc/cloud/cloud.cfg.d/05_logging.cfg
2022-05-11 03:18:56,050 - util.py[DEBUG]: Attempting to load yaml from string of length 1908 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:56,067 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,067 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,068 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,068 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,068 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,068 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,068 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,069 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,069 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,069 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,069 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,070 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,070 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,070 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,070 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,070 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,071 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,071 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,071 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,071 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,072 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,072 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,072 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,072 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,073 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,073 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,073 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,073 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,073 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,074 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,074 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,074 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,074 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,074 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,075 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,075 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,075 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,075 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,076 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,076 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,076 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,076 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,076 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,077 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,077 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,077 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,077 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,078 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,078 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,078 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,078 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,079 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,082 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instance/obj.pkl - wb: [256] 5703 bytes
2022-05-11 03:18:56,083 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/user-data.txt - wb: [384] 0 bytes
2022-05-11 03:18:56,093 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/user-data.txt.i - wb: [384] 318 bytes
2022-05-11 03:18:56,095 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/vendor-data.txt - wb: [384] 4 bytes~.y
2022-05-11 03:18:56,099 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/vendor-data.txt.i - wb: [384] 318 bytes
2022-05-11 03:18:56,105 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-11 03:18:56,105 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-11 03:18:56,105 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-11 03:18:56,106 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-11 03:18:56,106 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/consume_data - wb: [420] 23 bytes
2022-05-11 03:18:56,108 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/consume_data'>)
2022-05-11 03:18:56,108 - stages.py[DEBUG]: Added default handler for set(['text/cloud-config-jsonp', 'text/cloud-config']) from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2022-05-11 03:18:56,109 - stages.py[DEBUG]: Added default handler for set(['text/x-shellscript']) from ShellScriptPartHandler: [['text/x-shellscript']]
2022-05-11 03:18:56,109 - stages.py[DEBUG]: Added default handler for set(['text/cloud-boothook']) from BootHookPartHandler: [['text/cloud-boothook']]
2022-05-11 03:18:56,109 - stages.py[DEBUG]: Added default handler for set(['text/upstart-job']) from UpstartJobPartHandler: [['text/upstart-job']]
2022-05-11 03:18:56,110 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2022-05-11 03:18:56,111 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2022-05-11 03:18:56,111 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2022-05-11 03:18:56,111 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2022-05-11 03:18:56,112 - __init__.py[DEBUG]: {'Content-Type': 'text/x-not-multipart', 'Content-Disposition': 'attachment; filename="part-001"', 'MIME-Version': '1.0'}
2022-05-11 03:18:56,112 - __init__.py[DEBUG]: Empty payload of type text/x-not-multipart
2022-05-11 03:18:56,112 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2022-05-11 03:18:56,112 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2022-05-11 03:18:56,113 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2022-05-11 03:18:56,113 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/cloud-config.txt - wb: [384] 0 bytes
2022-05-11 03:18:56,115 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2022-05-11 03:18:56,115 - stages.py[DEBUG]: no vendordata from datasource
2022-05-11 03:18:56,115 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2022-05-11 03:18:56,116 - util.py[DEBUG]: Reading from /opt/freeware/etc/cloud/cloud.cfg (quiet=False)
2022-05-11 03:18:56,116 - util.py[DEBUG]: Read 2430 bytes from /opt/freeware/etc/cloud/cloud.cfg
2022-05-11 03:18:56,116 - util.py[DEBUG]: Attempting to load yaml from string of length 2430 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:56,154 - util.py[DEBUG]: Reading from /opt/freeware/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2022-05-11 03:18:56,155 - util.py[DEBUG]: Read 1908 bytes from /opt/freeware/etc/cloud/cloud.cfg.d/05_logging.cfg
2022-05-11 03:18:56,155 - util.py[DEBUG]: Attempting to load yaml from string of length 1908 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:56,172 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,172 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,172 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,172 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,173 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,173 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,173 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,173 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,174 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,174 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,174 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,174 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,174 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,175 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,175 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,175 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,175 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,176 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,176 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,176 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,176 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,176 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,177 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,177 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,177 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,177 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,178 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,178 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,178 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,178 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,178 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,179 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,179 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,179 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,179 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,180 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,180 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,180 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,180 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,180 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,181 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,181 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,181 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,181 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,182 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/cloud-config.txt (quiet=False)
2022-05-11 03:18:56,182 - util.py[DEBUG]: Read 0 bytes from /opt/freeware/var/lib/cloud/instance/cloud-config.txt
2022-05-11 03:18:56,182 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:56,182 - util.py[DEBUG]: load_yaml given empty string, returning default
2022-05-11 03:18:56,183 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,183 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,183 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,183 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,184 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,184 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,184 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,184 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,186 - util.py[DEBUG]: Reading from /opt/freeware/var/lib/cloud/instance/cloud-config.txt (quiet=False)
2022-05-11 03:18:56,186 - util.py[DEBUG]: Read 0 bytes from /opt/freeware/var/lib/cloud/instance/cloud-config.txt
2022-05-11 03:18:56,186 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<type 'dict'>,)
2022-05-11 03:18:56,187 - util.py[DEBUG]: load_yaml given empty string, returning default
2022-05-11 03:18:56,187 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:18:56,187 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:18:56,188 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:18:56,188 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:18:56,188 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:18:56,188 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:18:56,188 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:18:56,189 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:18:56,197 - importer.py[DEBUG]: Looking for modules ['cc_migrator', 'cloudinit.config.cc_migrator'] that have attributes ['handle']
2022-05-11 03:18:56,197 - importer.py[DEBUG]: Failed at attempted import of 'cc_migrator' due to: No module named cc_migrator
2022-05-11 03:18:56,199 - importer.py[DEBUG]: Found cc_migrator with attributes ['handle'] in ['cloudinit.config.cc_migrator']
2022-05-11 03:18:56,199 - importer.py[DEBUG]: Looking for modules ['cc_seed_random', 'cloudinit.config.cc_seed_random'] that have attributes ['handle']
2022-05-11 03:18:56,200 - importer.py[DEBUG]: Failed at attempted import of 'cc_seed_random' due to: No module named cc_seed_random
2022-05-11 03:18:56,202 - importer.py[DEBUG]: Found cc_seed_random with attributes ['handle'] in ['cloudinit.config.cc_seed_random']
2022-05-11 03:18:56,202 - importer.py[DEBUG]: Looking for modules ['cc_bootcmd', 'cloudinit.config.cc_bootcmd'] that have attributes ['handle']
2022-05-11 03:18:56,203 - importer.py[DEBUG]: Failed at attempted import of 'cc_bootcmd' due to: No module named cc_bootcmd
2022-05-11 03:18:56,205 - importer.py[DEBUG]: Found cc_bootcmd with attributes ['handle'] in ['cloudinit.config.cc_bootcmd']
2022-05-11 03:18:56,205 - importer.py[DEBUG]: Looking for modules ['cc_write_files', 'cloudinit.config.cc_write_files'] that have attributes ['handle']
2022-05-11 03:18:56,205 - importer.py[DEBUG]: Failed at attempted import of 'cc_write_files' due to: No module named cc_write_files
2022-05-11 03:18:56,206 - importer.py[DEBUG]: Found cc_write_files with attributes ['handle'] in ['cloudinit.config.cc_write_files']
2022-05-11 03:18:56,207 - importer.py[DEBUG]: Looking for modules ['cc_set_hostname', 'cloudinit.config.cc_set_hostname'] that have attributes ['handle']
2022-05-11 03:18:56,207 - importer.py[DEBUG]: Failed at attempted import of 'cc_set_hostname' due to: No module named cc_set_hostname
2022-05-11 03:18:56,210 - importer.py[DEBUG]: Found cc_set_hostname with attributes ['handle'] in ['cloudinit.config.cc_set_hostname']
2022-05-11 03:18:56,210 - importer.py[DEBUG]: Looking for modules ['cc_update_etc_hosts', 'cloudinit.config.cc_update_etc_hosts'] that have attributes ['handle']
2022-05-11 03:18:56,211 - importer.py[DEBUG]: Failed at attempted import of 'cc_update_etc_hosts' due to: No module named cc_update_etc_hosts
2022-05-11 03:18:56,213 - importer.py[DEBUG]: Found cc_update_etc_hosts with attributes ['handle'] in ['cloudinit.config.cc_update_etc_hosts']
2022-05-11 03:18:56,213 - importer.py[DEBUG]: Looking for modules ['cc_ca_certs', 'cloudinit.config.cc_ca_certs'] that have attributes ['handle']
2022-05-11 03:18:56,214 - importer.py[DEBUG]: Failed at attempted import of 'cc_ca_certs' due to: No module named cc_ca_certs
2022-05-11 03:18:56,215 - importer.py[DEBUG]: Found cc_ca_certs with attributes ['handle'] in ['cloudinit.config.cc_ca_certs']
2022-05-11 03:18:56,215 - importer.py[DEBUG]: Looking for modules ['cc_rsyslog', 'cloudinit.config.cc_rsyslog'] that have attributes ['handle']
2022-05-11 03:18:56,215 - importer.py[DEBUG]: Failed at attempted import of 'cc_rsyslog' due to: No module named cc_rsyslog
2022-05-11 03:18:56,218 - importer.py[DEBUG]: Found cc_rsyslog with attributes ['handle'] in ['cloudinit.config.cc_rsyslog']
2022-05-11 03:18:56,218 - importer.py[DEBUG]: Looking for modules ['cc_users_groups', 'cloudinit.config.cc_users_groups'] that have attributes ['handle']
2022-05-11 03:18:56,218 - importer.py[DEBUG]: Failed at attempted import of 'cc_users_groups' due to: No module named cc_users_groups
2022-05-11 03:18:56,219 - importer.py[DEBUG]: Found cc_users_groups with attributes ['handle'] in ['cloudinit.config.cc_users_groups']
2022-05-11 03:18:56,220 - importer.py[DEBUG]: Looking for modules ['cc_ssh', 'cloudinit.config.cc_ssh'] that have attributes ['handle']
2022-05-11 03:18:56,220 - importer.py[DEBUG]: Failed at attempted import of 'cc_ssh' due to: No module named cc_ssh
2022-05-11 03:18:56,222 - importer.py[DEBUG]: Found cc_ssh with attributes ['handle'] in ['cloudinit.config.cc_ssh']
2022-05-11 03:18:56,222 - importer.py[DEBUG]: Looking for modules ['cc_restore_volume_groups', 'cloudinit.config.cc_restore_volume_groups'] that have attributes ['handle']
2022-05-11 03:18:56,223 - importer.py[DEBUG]: Failed at attempted import of 'cc_restore_volume_groups' due to: No module named cc_restore_volume_groups
2022-05-11 03:18:56,224 - importer.py[DEBUG]: Found cc_restore_volume_groups with attributes ['handle'] in ['cloudinit.config.cc_restore_volume_groups']
2022-05-11 03:18:56,224 - importer.py[DEBUG]: Looking for modules ['cc_set_multipath_hcheck_interval', 'cloudinit.config.cc_set_multipath_hcheck_interval'] that have attributes ['handle']
2022-05-11 03:18:56,225 - importer.py[DEBUG]: Failed at attempted import of 'cc_set_multipath_hcheck_interval' due to: No module named cc_set_multipath_hcheck_interval
2022-05-11 03:18:56,226 - importer.py[DEBUG]: Found cc_set_multipath_hcheck_interval with attributes ['handle'] in ['cloudinit.config.cc_set_multipath_hcheck_interval']
2022-05-11 03:18:56,226 - importer.py[DEBUG]: Looking for modules ['cc_update_bootlist', 'cloudinit.config.cc_update_bootlist'] that have attributes ['handle']
2022-05-11 03:18:56,227 - importer.py[DEBUG]: Failed at attempted import of 'cc_update_bootlist' due to: No module named cc_update_bootlist
2022-05-11 03:18:56,228 - importer.py[DEBUG]: Found cc_update_bootlist with attributes ['handle'] in ['cloudinit.config.cc_update_bootlist']
2022-05-11 03:18:56,228 - importer.py[DEBUG]: Looking for modules ['cc_reset_rmc', 'cloudinit.config.cc_reset_rmc'] that have attributes ['handle']
2022-05-11 03:18:56,229 - importer.py[DEBUG]: Failed at attempted import of 'cc_reset_rmc' due to: No module named cc_reset_rmc
2022-05-11 03:18:56,230 - importer.py[DEBUG]: Found cc_reset_rmc with attributes ['handle'] in ['cloudinit.config.cc_reset_rmc']
2022-05-11 03:18:56,231 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-11 03:18:56,232 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-11 03:18:56,232 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-11 03:18:56,232 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-11 03:18:56,233 - stages.py[INFO]: Skipping modules ['ca-certs'] because they are not verified on distro 'aix'. To run anyway, add them to 'unverified_modules' in config.
2022-05-11 03:18:56,235 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0xb05f00cc>)
2022-05-11 03:18:56,236 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2022-05-11 03:18:56,237 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_seed_random - wb: [420] 23 bytes
2022-05-11 03:18:56,239 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_seed_random'>)
2022-05-11 03:18:56,241 - cc_seed_random.py[DEBUG]: command 'pollinate' not found for seed_command
2022-05-11 03:18:56,241 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0xb05f032c>)
2022-05-11 03:18:56,242 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2022-05-11 03:18:56,243 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_write_files - wb: [420] 23 bytes
2022-05-11 03:18:56,244 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_write_files'>)
2022-05-11 03:18:56,244 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2022-05-11 03:18:56,245 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_set_hostname - wb: [420] 23 bytes
2022-05-11 03:18:56,247 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_set_hostname'>)2022-05-11 03:18:56,247 - cc_set_hostname.py[DEBUG]: Setting the hostname to testforibm.jhacorp.com (testforibm)2022-05-11 03:18:56,248 - util.py[DEBUG]: Running command ['/usr/sbin/chdev', '-l', 'inet0', '-a', 'hostname=testforibm'] with allowed return codes [0] (shell=False, capture=True)2022-05-11 03:19:01,388 - util.py[DEBUG]: Running command ['/usr/bin/uname', '-S', 'testforibm'] with allowed return codes [0] (shell=False, capture=True)2022-05-11 03:19:01,399 - __init__.py[DEBUG]: Non-persistently setting the system hostname to testforibm2022-05-11 03:19:01,400 - util.py[DEBUG]: Running command ['hostname', u'testforibm'] with allowed return codes [0] (shell=False, capture=True)2022-05-11 03:19:01,429 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0xb05f022c>)2022-05-11 03:19:01,430 - cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts2022-05-11 03:19:01,431 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ca_certs - wb: [420] 23 bytes
2022-05-11 03:19:01,433 - helpers.py[DEBUG]: Running config-ca-certs using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ca_certs'>)
2022-05-11 03:19:01,434 - cc_ca_certs.py[DEBUG]: Skipping module named ca-certs, no 'ca-certs' key in configuration
2022-05-11 03:19:01,435 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_rsyslog - wb: [420] 23 bytes
2022-05-11 03:19:01,436 - helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_rsyslog'>)
2022-05-11 03:19:01,436 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
2022-05-11 03:19:01,437 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_users_groups - wb: [420] 23 bytes
2022-05-11 03:19:01,440 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_users_groups'>)
2022-05-11 03:19:01,441 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:01,441 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:01,441 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:01,441 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:01,442 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:01,442 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:01,442 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:01,442 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:01,443 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:01,443 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:01,443 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:01,443 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:01,444 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:01,444 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:01,444 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:01,444 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:01,445 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:01,445 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:01,445 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:01,445 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:01,445 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:01,446 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:01,446 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:01,446 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:01,447 - aix.py[INFO]: User root already exists, skipping.
2022-05-11 03:19:01,448 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ssh - wb: [420] 23 bytes
2022-05-11 03:19:01,450 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ssh'>)
2022-05-11 03:19:01,452 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key
2022-05-11 03:19:01,452 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key.pub
2022-05-11 03:19:01,453 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key
2022-05-11 03:19:01,454 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key.pub
2022-05-11 03:19:01,454 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=False)
2022-05-11 03:19:04,742 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'dsa', '-N', '', '-f', '/etc/ssh/ssh_host_dsa_key'] with allowed return codes [0] (shell=False, capture=False)
2022-05-11 03:19:05,293 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:05,293 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:05,294 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:05,294 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:05,294 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:05,294 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:05,295 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:05,295 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:05,295 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:05,296 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:05,296 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:05,296 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:05,296 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:05,296 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:05,297 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:05,297 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:05,297 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:05,297 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:05,297 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:05,298 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:05,298 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:05,298 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:05,298 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:05,299 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:05,300 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2022-05-11 03:19:05,301 - util.py[DEBUG]: Read 4474 bytes from /etc/ssh/sshd_config
2022-05-11 03:19:05,302 - util.py[WARNING]: Applying ssh credentials failed!
2022-05-11 03:19:05,302 - util.py[DEBUG]: Applying ssh credentials failed!
Traceback (most recent call last):
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_ssh.py", line 120, in handle
apply_credentials(keys, user, disable_root, disable_root_opts)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_ssh.py", line 129, in apply_credentials
ssh_util.setup_user_keys(keys, user)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 252, in setup_user_keys
(auth_key_fn, auth_key_entries) = extract_authorized_keys(username)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 220, in extract_authorized_keys
ssh_cfg = parse_ssh_config_map(DEF_SSHD_CFG)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 302, in parse_ssh_config_map
lines = parse_ssh_config(fname)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 296, in parse_ssh_config
(key, val) = line.split(None, 1)
ValueError: need more than 1 value to unpack
2022-05-11 03:19:05,306 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_restore_volume_groups - wb: [420] 23 bytes
2022-05-11 03:19:05,308 - helpers.py[DEBUG]: Running config-restore-volume-groups using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_restore_volume_groups'>)
2022-05-11 03:19:05,308 - cc_restore_volume_groups.py[DEBUG]: Attempting to restore non-rootVG volume groups.
2022-05-11 03:19:05,316 - util.py[DEBUG]: Running command ['/usr/sbin/lspv'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:05,337 - util.py[DEBUG]: Running command ['/usr/sbin/importvg', '-y', 'datavg', 'hdisk1'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,666 - cc_restore_volume_groups.py[DEBUG]: datavg
2022-05-11 03:19:08,666 - util.py[DEBUG]: Running command ['/usr/sbin/lsvg'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,677 - util.py[DEBUG]: Running command ['/usr/sbin/mount', 'all'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,734 - cc_restore_volume_groups.py[DEBUG]: Attempting to mount disks marked as auto-mounting resulted in errors. This is likely due to attempting to mount filesystems that are already mounted, therefore ignoring: Unexpected error while running command.
Command: ['/usr/sbin/mount', 'all']
Exit code: 3
Reason: -
Stdout: ''
Stderr: 'mount: /dev/hd1 on /home: Device busy\nmount: /dev/hd11admin on /admin: Device busy\nmount: /proc on /proc: Device busy\nmount: /dev/hd10opt on /opt: Device busy\nmount: /dev/livedump on /var/adm/ras/livedump: Device busy\n'.
2022-05-11 03:19:08,736 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_set_multipath_hcheck_interval - wb: [420] 23 bytes
2022-05-11 03:19:08,739 - helpers.py[DEBUG]: Running config-set-multipath-hcheck-interval using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_set_multipath_hcheck_interval'>)
2022-05-11 03:19:08,739 - cc_set_multipath_hcheck_interval.py[DEBUG]: Attempting to set the multipath hcheck interval to 60
2022-05-11 03:19:08,739 - util.py[DEBUG]: Running command ['/usr/sbin/lspath', '-F', 'name'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,759 - util.py[DEBUG]: Running command ['/usr/sbin/chdev', '-l', 'hdisk1', '-a', 'hcheck_interval=60', '-P'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,802 - cc_set_multipath_hcheck_interval.py[DEBUG]: hdisk1 changed
2022-05-11 03:19:08,802 - util.py[DEBUG]: Running command ['/usr/sbin/chdev', '-l', 'hdisk0', '-a', 'hcheck_interval=60', '-P'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,840 - cc_set_multipath_hcheck_interval.py[DEBUG]: hdisk0 changed
2022-05-11 03:19:08,842 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_update_bootlist - wb: [420] 23 bytes
2022-05-11 03:19:08,844 - helpers.py[DEBUG]: Running config-update-bootlist using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_update_bootlist'>)
2022-05-11 03:19:08,845 - cc_update_bootlist.py[DEBUG]: Attempting to configure the boot list.
2022-05-11 03:19:08,866 - util.py[DEBUG]: Running command ['/usr/sbin/bootinfo', '-b'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,880 - util.py[DEBUG]: Running command ['/usr/bin/bootlist', '-m', 'normal', '-o', 'hdisk0'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,912 - cc_update_bootlist.py[DEBUG]: hdisk0 blv=hd5 pathid=0
hdisk0 blv=hd5 pathid=1
2022-05-11 03:19:08,914 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_reset_rmc - wb: [420] 23 bytes
2022-05-11 03:19:08,917 - helpers.py[DEBUG]: Running config-reset-rmc using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_reset_rmc'>)
2022-05-11 03:19:08,917 - cc_reset_rmc.py[DEBUG]: tool is /usr/sbin/rsct/bin/rmcctrl
2022-05-11 03:19:08,918 - cc_reset_rmc.py[DEBUG]: tool is /usr/sbin/rsct/install/bin/recfgct
2022-05-11 03:19:08,918 - cc_reset_rmc.py[DEBUG]: Attempting to reset RMC.
2022-05-11 03:19:08,920 - util.py[DEBUG]: Running command ['/usr/bin/head', '-n1', '/etc/ct_node_id'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,930 - cc_reset_rmc.py[DEBUG]: Node ID at beginning of module: adca01a49e1be5cc
2022-05-11 03:19:08,930 - util.py[DEBUG]: Running command ['/usr/sbin/rsct/bin/rmcctrl', '-z'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:08,989 - util.py[DEBUG]: Running command ['/usr/sbin/rsct/install/bin/recfgct'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:13,308 - cc_reset_rmc.py[DEBUG]: /usr/lib/dr/scripts/all/ctrmc_MDdr DR script to refresh Management Domain configuration
0513-071 The ctcas Subsystem has been added.
0513-071 The ctrmc Subsystem has been added.
0513-059 The ctrmc Subsystem has been started. Subsystem PID is 5832842.
2022-05-11 03:19:13,308 - util.py[DEBUG]: Running command ['/usr/bin/head', '-n1', '/etc/ct_node_id'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:13,319 - cc_reset_rmc.py[DEBUG]: Node ID at end of module: 4c3dda8222829ccc
2022-05-11 03:19:13,320 - cloud-init[DEBUG]: Ran 14 modules with 0 failures
2022-05-11 03:19:13,337 - util.py[DEBUG]: cloud-init mode 'init' took 17.857 seconds (17.86)
2022-05-11 03:19:14,184 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'modules:config' at Wed, 11 May 2022 10:19:13 PST. Up 42.9643990993 seconds.
2022-05-11 03:19:14,186 - importer.py[DEBUG]: Looking for modules ['cc_emit_upstart', 'cloudinit.config.cc_emit_upstart'] that have attributes ['handle']
2022-05-11 03:19:14,187 - importer.py[DEBUG]: Failed at attempted import of 'cc_emit_upstart' due to: No module named cc_emit_upstart
2022-05-11 03:19:14,190 - importer.py[DEBUG]: Found cc_emit_upstart with attributes ['handle'] in ['cloudinit.config.cc_emit_upstart']
2022-05-11 03:19:14,191 - importer.py[DEBUG]: Looking for modules ['cc_disk_setup', 'cloudinit.config.cc_disk_setup'] that have attributes ['handle']
2022-05-11 03:19:14,191 - importer.py[DEBUG]: Failed at attempted import of 'cc_disk_setup' due to: No module named cc_disk_setup
2022-05-11 03:19:14,210 - importer.py[DEBUG]: Found cc_disk_setup with attributes ['handle'] in ['cloudinit.config.cc_disk_setup']
2022-05-11 03:19:14,210 - importer.py[DEBUG]: Looking for modules ['cc_mounts', 'cloudinit.config.cc_mounts'] that have attributes ['handle']
2022-05-11 03:19:14,211 - importer.py[DEBUG]: Failed at attempted import of 'cc_mounts' due to: No module named cc_mounts
2022-05-11 03:19:14,215 - importer.py[DEBUG]: Found cc_mounts with attributes ['handle'] in ['cloudinit.config.cc_mounts']
2022-05-11 03:19:14,215 - importer.py[DEBUG]: Looking for modules ['cc_ssh_import_id', 'cloudinit.config.cc_ssh_import_id'] that have attributes ['handle']
2022-05-11 03:19:14,216 - importer.py[DEBUG]: Failed at attempted import of 'cc_ssh_import_id' due to: No module named cc_ssh_import_id
2022-05-11 03:19:14,218 - importer.py[DEBUG]: Found cc_ssh_import_id with attributes ['handle'] in ['cloudinit.config.cc_ssh_import_id']
2022-05-11 03:19:14,220 - importer.py[DEBUG]: Looking for modules ['cc_locale', 'cloudinit.config.cc_locale'] that have attributes ['handle']
2022-05-11 03:19:14,221 - importer.py[DEBUG]: Failed at attempted import of 'cc_locale' due to: No module named cc_locale
2022-05-11 03:19:14,223 - importer.py[DEBUG]: Found cc_locale with attributes ['handle'] in ['cloudinit.config.cc_locale']
2022-05-11 03:19:14,224 - importer.py[DEBUG]: Looking for modules ['cc_set_passwords', 'cloudinit.config.cc_set_passwords'] that have attributes ['handle']
2022-05-11 03:19:14,225 - importer.py[DEBUG]: Failed at attempted import of 'cc_set_passwords' due to: No module named cc_set_passwords
2022-05-11 03:19:14,227 - importer.py[DEBUG]: Found cc_set_passwords with attributes ['handle'] in ['cloudinit.config.cc_set_passwords']
2022-05-11 03:19:14,227 - importer.py[DEBUG]: Looking for modules ['cc_package_update_upgrade_install', 'cloudinit.config.cc_package_update_upgrade_install'] that have attributes ['handle']
2022-05-11 03:19:14,228 - importer.py[DEBUG]: Failed at attempted import of 'cc_package_update_upgrade_install' due to: No module named cc_package_update_upgrade_install
2022-05-11 03:19:14,230 - importer.py[DEBUG]: Found cc_package_update_upgrade_install with attributes ['handle'] in ['cloudinit.config.cc_package_update_upgrade_install']
2022-05-11 03:19:14,230 - importer.py[DEBUG]: Looking for modules ['cc_landscape', 'cloudinit.config.cc_landscape'] that have attributes ['handle']
2022-05-11 03:19:14,231 - importer.py[DEBUG]: Failed at attempted import of 'cc_landscape' due to: No module named cc_landscape
2022-05-11 03:19:14,235 - importer.py[DEBUG]: Found cc_landscape with attributes ['handle'] in ['cloudinit.config.cc_landscape']
2022-05-11 03:19:14,235 - importer.py[DEBUG]: Looking for modules ['cc_timezone', 'cloudinit.config.cc_timezone'] that have attributes ['handle']
2022-05-11 03:19:14,237 - importer.py[DEBUG]: Failed at attempted import of 'cc_timezone' due to: No module named cc_timezone
2022-05-11 03:19:14,239 - importer.py[DEBUG]: Found cc_timezone with attributes ['handle'] in ['cloudinit.config.cc_timezone']
2022-05-11 03:19:14,239 - importer.py[DEBUG]: Looking for modules ['cc_puppet', 'cloudinit.config.cc_puppet'] that have attributes ['handle']
2022-05-11 03:19:14,244 - importer.py[DEBUG]: Failed at attempted import of 'cc_puppet' due to: No module named cc_puppet
2022-05-11 03:19:14,246 - importer.py[DEBUG]: Found cc_puppet with attributes ['handle'] in ['cloudinit.config.cc_puppet']
2022-05-11 03:19:14,249 - importer.py[DEBUG]: Looking for modules ['cc_chef', 'cloudinit.config.cc_chef'] that have attributes ['handle']
2022-05-11 03:19:14,249 - importer.py[DEBUG]: Failed at attempted import of 'cc_chef' due to: No module named cc_chef
2022-05-11 03:19:14,254 - importer.py[DEBUG]: Found cc_chef with attributes ['handle'] in ['cloudinit.config.cc_chef']
2022-05-11 03:19:14,254 - importer.py[DEBUG]: Looking for modules ['cc_salt_minion', 'cloudinit.config.cc_salt_minion'] that have attributes ['handle']
2022-05-11 03:19:14,255 - importer.py[DEBUG]: Failed at attempted import of 'cc_salt_minion' due to: No module named cc_salt_minion
2022-05-11 03:19:14,256 - importer.py[DEBUG]: Found cc_salt_minion with attributes ['handle'] in ['cloudinit.config.cc_salt_minion']
2022-05-11 03:19:14,256 - importer.py[DEBUG]: Looking for modules ['cc_mcollective', 'cloudinit.config.cc_mcollective'] that have attributes ['handle']
2022-05-11 03:19:14,257 - importer.py[DEBUG]: Failed at attempted import of 'cc_mcollective' due to: No module named cc_mcollective
2022-05-11 03:19:14,258 - importer.py[DEBUG]: Found cc_mcollective with attributes ['handle'] in ['cloudinit.config.cc_mcollective']
2022-05-11 03:19:14,259 - importer.py[DEBUG]: Looking for modules ['cc_disable_ec2_metadata', 'cloudinit.config.cc_disable_ec2_metadata'] that have attributes ['handle']
2022-05-11 03:19:14,259 - importer.py[DEBUG]: Failed at attempted import of 'cc_disable_ec2_metadata' due to: No module named cc_disable_ec2_metadata
2022-05-11 03:19:14,260 - importer.py[DEBUG]: Found cc_disable_ec2_metadata with attributes ['handle'] in ['cloudinit.config.cc_disable_ec2_metadata']
2022-05-11 03:19:14,261 - importer.py[DEBUG]: Looking for modules ['cc_runcmd', 'cloudinit.config.cc_runcmd'] that have attributes ['handle']
2022-05-11 03:19:14,261 - importer.py[DEBUG]: Failed at attempted import of 'cc_runcmd' due to: No module named cc_runcmd
2022-05-11 03:19:14,262 - importer.py[DEBUG]: Found cc_runcmd with attributes ['handle'] in ['cloudinit.config.cc_runcmd']
2022-05-11 03:19:14,263 - importer.py[DEBUG]: Looking for modules ['cc_byobu', 'cloudinit.config.cc_byobu'] that have attributes ['handle']
2022-05-11 03:19:14,263 - importer.py[DEBUG]: Failed at attempted import of 'cc_byobu' due to: No module named cc_byobu
2022-05-11 03:19:14,264 - importer.py[DEBUG]: Found cc_byobu with attributes ['handle'] in ['cloudinit.config.cc_byobu']
2022-05-11 03:19:14,266 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-11 03:19:14,266 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-11 03:19:14,267 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-11 03:19:14,267 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-11 03:19:14,269 - stages.py[INFO]: Skipping modules ['emit_upstart', 'ssh-import-id', 'landscape', 'byobu'] because they are not verified on distro 'aix'. To run anyway, add them to 'unverified_modules' in config.
2022-05-11 03:19:14,271 - helpers.py[DEBUG]: Running config-emit_upstart using lock (<cloudinit.helpers.DummyLock object at 0xb056ae4c>)
2022-05-11 03:19:14,271 - cc_emit_upstart.py[DEBUG]: Skipping module named emit_upstart, no /sbin/initctl located
2022-05-11 03:19:14,274 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_disk_setup - wb: [420] 23 bytes
2022-05-11 03:19:14,275 - helpers.py[DEBUG]: Running config-disk_setup using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_disk_setup'>)
2022-05-11 03:19:14,277 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_mounts - wb: [420] 23 bytes
2022-05-11 03:19:14,282 - helpers.py[DEBUG]: Running config-mounts using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_mounts'>)
2022-05-11 03:19:14,283 - cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0
2022-05-11 03:19:14,283 - openstack.py[DEBUG]: Using ec2 style lookup to find device ['ephemeral0']
2022-05-11 03:19:14,284 - openstack.py[DEBUG]: Using openstack style lookup to find device ['ephemeral0']
2022-05-11 03:19:14,284 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=ephemeral0', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2022-05-11 03:19:14,307 - cc_mounts.py[DEBUG]: Ignoring nonexistant default named mount ephemeral0
2022-05-11 03:19:14,308 - cc_mounts.py[DEBUG]: Attempting to determine the real name of swap
2022-05-11 03:19:14,308 - openstack.py[DEBUG]: Using ec2 style lookup to find device ['swap']
2022-05-11 03:19:14,309 - openstack.py[DEBUG]: Using openstack style lookup to find device ['swap']
2022-05-11 03:19:14,309 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=swap', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2022-05-11 03:19:14,324 - cc_mounts.py[DEBUG]: Ignoring nonexistant default named mount swap
2022-05-11 03:19:14,324 - cc_mounts.py[DEBUG]: No modifications to fstab needed.
2022-05-11 03:19:14,327 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ssh_import_id - wb: [420] 23 bytes
2022-05-11 03:19:14,329 - helpers.py[DEBUG]: Running config-ssh-import-id using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ssh_import_id'>)
2022-05-11 03:19:14,330 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:14,330 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:14,330 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:14,330 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:14,331 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:14,331 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:14,331 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:14,332 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:14,332 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:14,332 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:14,333 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:14,333 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:14,333 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:14,335 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:14,335 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:14,335 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:14,335 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:14,336 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:14,336 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:14,336 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:14,337 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:14,337 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:14,337 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:14,337 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:14,339 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_locale - wb: [420] 23 bytes
2022-05-11 03:19:14,341 - helpers.py[DEBUG]: Running config-locale using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_locale'>)
2022-05-11 03:19:14,341 - cc_locale.py[DEBUG]: Setting locale to en_US
2022-05-11 03:19:14,341 - util.py[DEBUG]: Running command ['/usr/bin/chlang', '-M', 'en_US'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:14,405 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_set_passwords - wb: [420] 22 bytes
2022-05-11 03:19:14,408 - helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_set_passwords'>)
2022-05-11 03:19:14,408 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2022-05-11 03:19:14,409 - util.py[DEBUG]: Read 4474 bytes from /etc/ssh/sshd_config
2022-05-11 03:19:14,409 - util.py[WARNING]: Running set-passwords (<module 'cloudinit.config.cc_set_passwords' from '/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_set_passwords.pyc'>) failed
2022-05-11 03:19:14,410 - util.py[DEBUG]: Running set-passwords (<module 'cloudinit.config.cc_set_passwords' from '/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_set_passwords.pyc'>) failed
Traceback (most recent call last):
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/stages.py", line 658, in _run_modules
cc.run(run_name, mod.handle, func_args, freq=freq)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/cloud.py", line 63, in run
return self._runners.run(name, functor, args, freq, clear_on_fail)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/helpers.py", line 197, in run
results = functor(*args)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_set_passwords.py", line 121, in handle
old_lines = ssh_util.parse_ssh_config(ssh_util.DEF_SSHD_CFG)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 296, in parse_ssh_config
(key, val) = line.split(None, 1)
ValueError: need more than 1 value to unpack
2022-05-11 03:19:14,415 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_package_update_upgrade_install - wb: [420] 23 bytes
2022-05-11 03:19:14,417 - helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_package_update_upgrade_install'>)
2022-05-11 03:19:14,419 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_landscape - wb: [420] 23 bytes
2022-05-11 03:19:14,422 - helpers.py[DEBUG]: Running config-landscape using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_landscape'>)
2022-05-11 03:19:14,423 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_timezone - wb: [420] 23 bytes
2022-05-11 03:19:14,425 - helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_timezone'>)
2022-05-11 03:19:14,426 - cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified
2022-05-11 03:19:14,427 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_puppet - wb: [420] 23 bytes
2022-05-11 03:19:14,430 - helpers.py[DEBUG]: Running config-puppet using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_puppet'>)
2022-05-11 03:19:14,430 - cc_puppet.py[DEBUG]: Skipping module named puppet, no 'puppet' configuration found
2022-05-11 03:19:14,432 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_chef - wb: [420] 23 bytes
2022-05-11 03:19:14,433 - helpers.py[DEBUG]: Running config-chef using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_chef'>)
2022-05-11 03:19:14,433 - cc_chef.py[DEBUG]: Skipping module named chef, no 'chef' key in configuration
2022-05-11 03:19:14,434 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_salt_minion - wb: [420] 23 bytes
2022-05-11 03:19:14,437 - helpers.py[DEBUG]: Running config-salt-minion using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_salt_minion'>)
2022-05-11 03:19:14,437 - cc_salt_minion.py[DEBUG]: Skipping module named salt-minion, no 'salt_minion' key in configuration
2022-05-11 03:19:14,438 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_mcollective - wb: [420] 23 bytes
2022-05-11 03:19:14,440 - helpers.py[DEBUG]: Running config-mcollective using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_mcollective'>)
2022-05-11 03:19:14,441 - cc_mcollective.py[DEBUG]: Skipping module named mcollective, no 'mcollective' key in configuration
2022-05-11 03:19:14,441 - helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock (<cloudinit.helpers.DummyLock object at 0xb05baaac>)
2022-05-11 03:19:14,442 - cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled
2022-05-11 03:19:14,443 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_runcmd - wb: [420] 23 bytes
2022-05-11 03:19:14,446 - helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_runcmd'>)
2022-05-11 03:19:14,446 - cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration
2022-05-11 03:19:14,447 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_byobu - wb: [420] 23 bytes
2022-05-11 03:19:14,450 - helpers.py[DEBUG]: Running config-byobu using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_byobu'>)
2022-05-11 03:19:14,450 - cc_byobu.py[DEBUG]: Skipping module named byobu, no 'byobu' values found
2022-05-11 03:19:14,451 - cloud-init[DEBUG]: Ran 16 modules with 1 failures
2022-05-11 03:19:14,467 - util.py[DEBUG]: cloud-init mode 'modules' took 0.530 seconds (0.53)
2022-05-11 03:19:15,294 - util.py[DEBUG]: Cloud-init v. 0.7.5 running 'modules:final' at Wed, 11 May 2022 10:19:15 PST. Up 44.0808579922 seconds.
2022-05-11 03:19:15,295 - importer.py[DEBUG]: Looking for modules ['cc_rightscale_userdata', 'cloudinit.config.cc_rightscale_userdata'] that have attributes ['handle']
2022-05-11 03:19:15,296 - importer.py[DEBUG]: Failed at attempted import of 'cc_rightscale_userdata' due to: No module named cc_rightscale_userdata
2022-05-11 03:19:15,297 - importer.py[DEBUG]: Found cc_rightscale_userdata with attributes ['handle'] in ['cloudinit.config.cc_rightscale_userdata']
2022-05-11 03:19:15,297 - importer.py[DEBUG]: Looking for modules ['cc_scripts_vendor', 'cloudinit.config.cc_scripts_vendor'] that have attributes ['handle']
2022-05-11 03:19:15,298 - importer.py[DEBUG]: Failed at attempted import of 'cc_scripts_vendor' due to: No module named cc_scripts_vendor
2022-05-11 03:19:15,301 - importer.py[DEBUG]: Found cc_scripts_vendor with attributes ['handle'] in ['cloudinit.config.cc_scripts_vendor']
2022-05-11 03:19:15,301 - importer.py[DEBUG]: Looking for modules ['cc_scripts_per_once', 'cloudinit.config.cc_scripts_per_once'] that have attributes ['handle']
2022-05-11 03:19:15,302 - importer.py[DEBUG]: Failed at attempted import of 'cc_scripts_per_once' due to: No module named cc_scripts_per_once
2022-05-11 03:19:15,303 - importer.py[DEBUG]: Found cc_scripts_per_once with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_once']
2022-05-11 03:19:15,303 - importer.py[DEBUG]: Looking for modules ['cc_scripts_per_boot', 'cloudinit.config.cc_scripts_per_boot'] that have attributes ['handle']
2022-05-11 03:19:15,304 - importer.py[DEBUG]: Failed at attempted import of 'cc_scripts_per_boot' due to: No module named cc_scripts_per_boot
2022-05-11 03:19:15,305 - importer.py[DEBUG]: Found cc_scripts_per_boot with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_boot']
2022-05-11 03:19:15,305 - importer.py[DEBUG]: Looking for modules ['cc_scripts_per_instance', 'cloudinit.config.cc_scripts_per_instance'] that have attributes ['handle']
2022-05-11 03:19:15,305 - importer.py[DEBUG]: Failed at attempted import of 'cc_scripts_per_instance' due to: No module named cc_scripts_per_instance
2022-05-11 03:19:15,306 - importer.py[DEBUG]: Found cc_scripts_per_instance with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_instance']
2022-05-11 03:19:15,307 - importer.py[DEBUG]: Looking for modules ['cc_scripts_user', 'cloudinit.config.cc_scripts_user'] that have attributes ['handle']
2022-05-11 03:19:15,307 - importer.py[DEBUG]: Failed at attempted import of 'cc_scripts_user' due to: No module named cc_scripts_user
2022-05-11 03:19:15,308 - importer.py[DEBUG]: Found cc_scripts_user with attributes ['handle'] in ['cloudinit.config.cc_scripts_user']
2022-05-11 03:19:15,308 - importer.py[DEBUG]: Looking for modules ['cc_ssh_authkey_fingerprints', 'cloudinit.config.cc_ssh_authkey_fingerprints'] that have attributes ['handle']
2022-05-11 03:19:15,309 - importer.py[DEBUG]: Failed at attempted import of 'cc_ssh_authkey_fingerprints' due to: No module named cc_ssh_authkey_fingerprints
2022-05-11 03:19:15,310 - importer.py[DEBUG]: Found cc_ssh_authkey_fingerprints with attributes ['handle'] in ['cloudinit.config.cc_ssh_authkey_fingerprints']
2022-05-11 03:19:15,311 - importer.py[DEBUG]: Looking for modules ['cc_keys_to_console', 'cloudinit.config.cc_keys_to_console'] that have attributes ['handle']
2022-05-11 03:19:15,311 - importer.py[DEBUG]: Failed at attempted import of 'cc_keys_to_console' due to: No module named cc_keys_to_console
2022-05-11 03:19:15,312 - importer.py[DEBUG]: Found cc_keys_to_console with attributes ['handle'] in ['cloudinit.config.cc_keys_to_console']
2022-05-11 03:19:15,313 - importer.py[DEBUG]: Looking for modules ['cc_phone_home', 'cloudinit.config.cc_phone_home'] that have attributes ['handle']
2022-05-11 03:19:15,313 - importer.py[DEBUG]: Failed at attempted import of 'cc_phone_home' due to: No module named cc_phone_home
2022-05-11 03:19:15,314 - importer.py[DEBUG]: Found cc_phone_home with attributes ['handle'] in ['cloudinit.config.cc_phone_home']
2022-05-11 03:19:15,315 - importer.py[DEBUG]: Looking for modules ['cc_final_message', 'cloudinit.config.cc_final_message'] that have attributes ['handle']
2022-05-11 03:19:15,315 - importer.py[DEBUG]: Failed at attempted import of 'cc_final_message' due to: No module named cc_final_message
2022-05-11 03:19:15,316 - importer.py[DEBUG]: Found cc_final_message with attributes ['handle'] in ['cloudinit.config.cc_final_message']
2022-05-11 03:19:15,316 - importer.py[DEBUG]: Looking for modules ['cc_power_state_change', 'cloudinit.config.cc_power_state_change'] that have attributes ['handle']
2022-05-11 03:19:15,317 - importer.py[DEBUG]: Failed at attempted import of 'cc_power_state_change' due to: No module named cc_power_state_change
2022-05-11 03:19:15,318 - importer.py[DEBUG]: Found cc_power_state_change with attributes ['handle'] in ['cloudinit.config.cc_power_state_change']
2022-05-11 03:19:15,319 - importer.py[DEBUG]: Looking for modules ['aix', 'cloudinit.distros.aix'] that have attributes ['Distro']
2022-05-11 03:19:15,320 - importer.py[DEBUG]: Failed at attempted import of 'aix' due to: No module named aix
2022-05-11 03:19:15,320 - importer.py[DEBUG]: Found aix with attributes ['Distro'] in ['cloudinit.distros.aix']
2022-05-11 03:19:15,320 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.aix.Distro'>
2022-05-11 03:19:15,323 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_rightscale_userdata - wb: [420] 23 bytes
2022-05-11 03:19:15,324 - helpers.py[DEBUG]: Running config-rightscale_userdata using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_rightscale_userdata'>)
2022-05-11 03:19:15,325 - cc_rightscale_userdata.py[DEBUG]: Failed to get raw userdata in module rightscale_userdata
2022-05-11 03:19:15,326 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_scripts_vendor - wb: [420] 23 bytes
2022-05-11 03:19:15,328 - helpers.py[DEBUG]: Running config-scripts-vendor using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_scripts_vendor'>)
2022-05-11 03:19:15,329 - helpers.py[DEBUG]: config-scripts-per-once already ran (freq=once)
2022-05-11 03:19:15,330 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0xb056ab2c>)
2022-05-11 03:19:15,331 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_scripts_per_instance - wb: [420] 23 bytes
2022-05-11 03:19:15,332 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_scripts_per_instance'>)
2022-05-11 03:19:15,333 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_scripts_user - wb: [420] 23 bytes
2022-05-11 03:19:15,335 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_scripts_user'>)
2022-05-11 03:19:15,336 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ssh_authkey_fingerprints - wb: [420] 23 bytes
2022-05-11 03:19:15,338 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_ssh_authkey_fingerprints'>)
2022-05-11 03:19:15,338 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:15,338 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:15,338 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:15,339 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:15,339 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:15,339 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:15,339 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:15,339 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:15,340 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:15,340 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:15,340 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:15,340 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:15,341 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:15,341 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:15,341 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:15,341 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:15,342 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2022-05-11 03:19:15,342 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2022-05-11 03:19:15,342 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2022-05-11 03:19:15,342 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2022-05-11 03:19:15,342 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2022-05-11 03:19:15,343 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2022-05-11 03:19:15,343 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2022-05-11 03:19:15,343 - __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
2022-05-11 03:19:15,344 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2022-05-11 03:19:15,344 - util.py[DEBUG]: Read 4474 bytes from /etc/ssh/sshd_config
2022-05-11 03:19:15,345 - util.py[WARNING]: Running ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.pyc'>) failed
2022-05-11 03:19:15,345 - util.py[DEBUG]: Running ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.pyc'>) failed
Traceback (most recent call last):
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/stages.py", line 658, in _run_modules
cc.run(run_name, mod.handle, func_args, freq=freq)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/cloud.py", line 63, in run
return self._runners.run(name, functor, args, freq, clear_on_fail)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/helpers.py", line 197, in run
results = functor(*args)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py", line 102, in handle
(key_fn, key_entries) = ssh_util.extract_authorized_keys(user_name)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 220, in extract_authorized_keys
ssh_cfg = parse_ssh_config_map(DEF_SSHD_CFG)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 302, in parse_ssh_config_map
lines = parse_ssh_config(fname)
File "/opt/freeware/lib/python2.7/site-packages/cloudinit/ssh_util.py", line 296, in parse_ssh_config
(key, val) = line.split(None, 1)
ValueError: need more than 1 value to unpack
2022-05-11 03:19:15,348 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_keys_to_console - wb: [420] 23 bytes
2022-05-11 03:19:15,350 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_keys_to_console'>)
2022-05-11 03:19:15,350 - util.py[DEBUG]: Running command ['/opt/freeware/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True)
2022-05-11 03:19:15,373 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_phone_home - wb: [420] 23 bytes
2022-05-11 03:19:15,375 - helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_phone_home'>)
2022-05-11 03:19:15,376 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
2022-05-11 03:19:15,376 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0xb05c990c>)
2022-05-11 03:19:15,401 - util.py[DEBUG]: Cloud-init v. 0.7.5 finished at Wed, 11 May 2022 10:19:15 PST. Datasource DataSourceConfigDriveNet [net,ver=2][source=cd0]. Up 44.3893311024 seconds
2022-05-11 03:19:15,401 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instance/boot-finished - wb: [420] 57 bytes
2022-05-11 03:19:15,404 - util.py[DEBUG]: Writing to /opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_power_state_change - wb: [420] 22 bytes
2022-05-11 03:19:15,405 - helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/opt/freeware/var/lib/cloud/instances/592808f8-1eb2-45a8-ade2-78896b45dad4/sem/config_power_state_change'>)
2022-05-11 03:19:15,405 - cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing
2022-05-11 03:19:15,406 - cloud-init[DEBUG]: Ran 11 modules with 1 failures
2022-05-11 03:19:15,409 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../opt/freeware/var/lib/cloud/data/result.json'
2022-05-11 03:19:15,423 - util.py[DEBUG]: cloud-init mode 'modules' took 0.370 seconds (0.37)
------------------------------
Karen Van Gogh
Jack Henry and Associates
kvangogh@jackhenry.com------------------------------
Original Message:
Sent: Wed May 11, 2022 09:14 AM
From: Karen Van Gogh
Subject: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition
attempt to upload files failed
------------------------------
Karen Van Gogh
Jack Henry and Associates
kvangogh@jackhenry.com
Original Message:
Sent: Thu May 05, 2022 11:33 AM
From: Karen Van Gogh
Subject: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition
I have ran into a problem with deploys and the hostname given to the partition. Problem started after updating to PowerVC 2.0.1.1.
The hostname entered is not what is deployed on the partition.
I have not enabled DNS function to assign the hostname however it is doing a reverse lookup on the ip address and if it finds a resolvable ip address in DNS it will use that name instead of the name I have given the partition.
How can that be disabled or blocked in the cloud.cfg. I tested with a generic cloud.cfg file and it is doing a reverse lookup and assigning that ip hostname to the partition.
this behavior started after updating to 2.0.1.1 from 1.4.4.
I tested using the default cloud.cfg file with minor modifications. I can see in the cloud-init.log where it assigns the incorrect hostname. Where is it doing the logic to get that hostname and how do I fix it to use the hostname i am using. I am not sure where in the process its actually pulling the resolvable hostname and replacing what I set as the hostname with the other hostname it found in DNS.
I had our DNS admins go through and delete any old reverse lookups that were orphaned and deployed then looked at the cloud-init.log and they look the same but the correct hostname is in the log on the partitions that deployed the correct name on the partition. Only the partitions where a reverse resolvable ip existed is where the hostname is not set correctly.
Karen Van Gogh
Sys/Ntwk Admstr,Advsry
kvangogh@jackhenry.com
------------------------------
Karen Van Gogh
------------------------------