AIX Open Source

 View Only
Expand all | Collapse all

PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

  • 1.  PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Thu May 05, 2022 05:00 PM

    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
    ------------------------------


  • 2.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Fri May 06, 2022 11:55 AM
    Hello, cloud-init has no changes in last a couple of years. Can you show the version of cloud-init by running "rpm -qa | grep cloud-int"?
    "preserve_hostname" in cloud.cfg is used to manage hostname modules for setup and update operations. Its default value is "false", if you change to "True", it will prevent to update hostname. If you already did that and it still failed, we might have to look at the log.

    ------------------------------
    Rae Yang
    ------------------------------



  • 3.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Fri May 06, 2022 12:27 PM

    -qa | grep cloud-init

    cloud-init-0.7.5-4.3.ppc

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     

    NOTICE: This electronic mail message and any files transmitted with it are intended
    exclusively for the individual or entity to which it is addressed. The message,
    together with any attachment, may contain confidential and/or privileged information.
    Any unauthorized review, use, printing, saving, copying, disclosure or distribution
    is strictly prohibited. If you have received this message in error, please
    immediately advise the sender by reply email and delete all copies.






  • 4.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Fri May 06, 2022 12:35 PM

    preserve_hostname: false

     

    Here is our cloud.cfg file: Using this default cloud.cfg it fails in the log file I can see where it is changing then name to a name that is resolved in the reverse lookup of DNS.

     

    #Cat cloud.cfg

    # The top level settings are used as module

    # and system configuration.

     

    # A set of users which may be applied and/or used by various modules

    # when a 'default' entry is found it will reference the 'default_user'

    # from the distro configuration specified below

    users:

       - default

     

    # If this is set, 'root' will not be able to ssh in and they

    # will get a message to login instead as the above $user (ubuntu)

    disable_root: false

     

    # Allow SSH password authorization

    ssh_pwauth: true

     

    # Delete existing SSH host keys

    ssh_deletekeys: true

     

    # Regen rsa and dsa host keys

    ssh_genkeytypes: ['rsa', 'dsa']

     

    # This will cause the set+update hostname module to not operate (if true)

    preserve_hostname: false

     

    datasource_list: ['ConfigDrive']

     

    # Example datasource config

    # datasource:

    #    Ec2:

    #      metadata_urls: [ 'blah.com' ]

    #      timeout: 5 # (defaults to 50 seconds)

    #      max_wait: 10 # (defaults to 120 seconds)

     

    # The modules that run in the 'init' stage

    cloud_init_modules:

    - migrator

    - seed_random

    - bootcmd

    - write-files

    - set_hostname

    - update_etc_hosts

    - ca-certs

    - rsyslog

    - users-groups

    - ssh

    - restore-volume-groups

    - set-multipath-hcheck-interval

    - update-bootlist

    - reset-rmc

     

    # The modules that run in the 'config' stage

    cloud_config_modules:

    # Emit the cloud config ready event

    # this can be used by upstart jobs for 'start on cloud-config'.

    - emit_upstart

    - disk_setup

    - mounts

    - ssh-import-id

    - locale

    - set-passwords

    - package-update-upgrade-install

    - landscape

    - timezone

    - puppet

    - chef

    - salt-minion

    - mcollective

    - disable-ec2-metadata

    - runcmd

    - byobu

     

    # The modules that run in the 'final' stage

    cloud_final_modules:

    - rightscale_userdata

    - scripts-vendor

    - scripts-per-once

    - scripts-per-boot

    - scripts-per-instance

    - scripts-user

    - ssh-authkey-fingerprints

    - keys-to-console

    - phone-home

    - final-message

    - power-state-change

     

    # System and/or distro specific settings

    # (not accessible to handlers/transforms)

    system_info:

       # This will affect which distro class gets used

       distro: aix

       # Default user name + that default users groups (if added/used)

       default_user:

         name: root

         lock_passwd: false

       # Other config here will be given to the distro class and/or path classes

       paths:

          cloud_dir: /opt/freeware/var/lib/cloud/

          templates_dir: /opt/freeware/etc/cloud/templates/

          upstart_dir: /etc/rc.d/init.d/

       ssh_svcname: ssh

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     






  • 5.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Fri May 06, 2022 04:37 PM
    I currently have a case open with IBM support on this issue but due to AIX opensource support structure i was advised to open a conversation about the problem I am having with the community forum. CASE TS008624679
    I can provide any log files you need.


    ------------------------------
    Karen Van Gogh
    ------------------------------



  • 6.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Mon May 09, 2022 03:51 AM
    Hi Karen,

    How did you install cloud-init ? Was it installed from AIX toolbox or it was an AIX cloud image ?

    ------------------------------
    SANKET RATHI
    ------------------------------



  • 7.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Mon May 09, 2022 10:19 AM
    AIX toolbox from the IBM site.

    ------------------------------
    Karen Van Gogh
    ------------------------------



  • 8.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Wed May 11, 2022 12:30 PM
    I think we are having a fix missing in AIX toolbox version of cloud-init and we will upload the fixed version. 
    You may want to try with that if that fixes you problem. I will update once it is available on AIX toolbox.

    ------------------------------
    SANKET RATHI
    ------------------------------



  • 9.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Wed May 11, 2022 12:47 PM
    cloud-init 0.7.5-4.4 is available on AIX toolbox. Can you please update and verify if you still have the problem.

    ------------------------------
    SANKET RATHI
    ------------------------------



  • 10.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Wed May 11, 2022 02:02 PM

    I have updated it. I still do not see a module its calling cc_set_hostname it says not found.

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     

    NOTICE: This electronic mail message and any files transmitted with it are intended
    exclusively for the individual or entity to which it is addressed. The message,
    together with any attachment, may contain confidential and/or privileged information.
    Any unauthorized review, use, printing, saving, copying, disclosure or distribution
    is strictly prohibited. If you have received this message in error, please
    immediately advise the sender by reply email and delete all copies.






  • 11.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Wed May 11, 2022 04:15 PM

    Updated to the latest level and retested with the same results: I had a partition that it named   smocommvaultlab .. I entered the name: smolabibmtst51122p6

    I mounted the cd0 to /mnt and looked around in the directories and in the meta-data.json i do see the correct name in the files so I am not sure where its picking the incorrect name.

     

    #/opt/freeware/bin/cloud-init --version

    cloud-init 0.7.5

    root@smocommvaultlab #yum update cloud-init

    Setting up Update Process

    No Packages marked for Update

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     

    NOTICE: This electronic mail message and any files transmitted with it are intended
    exclusively for the individual or entity to which it is addressed. The message,
    together with any attachment, may contain confidential and/or privileged information.
    Any unauthorized review, use, printing, saving, copying, disclosure or distribution
    is strictly prohibited. If you have received this message in error, please
    immediately advise the sender by reply email and delete all copies.






  • 12.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Wed May 11, 2022 04:38 PM

    I do see in /mnt/openstack/latest in meta_data.json where it has the incorrect name. Not sure how all that works just searching for locations of correct or incorrect hostnames.

    #Cat meta*

    {"uuid": "c6fc9e8c-17d2-4c9b-9710-b2f46dda2f7b", "hostname": "smocommvaultlab.jhacorp.com", "admin_pass": "jKmy2QDEJV7B", "network_config": {"name": "network_config", "content_path": "/content/0000"}, "name": "smolabibmtst51122p6", "launch_index": 0, "availability_zone": "Default Group", "random_seed": "Lt3tPNFSpa7SOHynqW61eofdwanHVAR5+QpfskfisCrZgp5Q7KFdkU9cav3vITYYUzJ+M1jZsbv5975eNDUFVAWYBr4u1BEVz+2yDWn5J/vsQpf2SM0R9zk1aXlFojuBEFe8M+jztB/WQcyGo9MDRu80+wkx4XJgBR1Kqi0KGPE2jd1/Zsy9mS54QCAfLooGbUhrdjQRNezurEC4/nNmeOWXEd6B6smgkRpxYHNTBZnGbeaQciq9A21fEtEjISSpJUgsAT+z9OmIq0EElBbBtY8AZ04cRx642QtBg42fZZL3EWWCZTvaVrgq6TmQ/IY5IjIny3DEzCfoXf/8bSJ6fMqUwmiTEz5Bm6F/pdhD+WKcfUpFVLpQ/tqxixp+pdZcUvHDXFhsEOrR0qOkRQAH1W6Wz72YuPbufJOzUYmrb5iQa5iLAe3ieHf+8rNneOk/08Wxe9GqZAjXft8Fk9wj1hJA4yBp1rCUgICOwyHLOGcYRrNwz7gJhIN2GSj7GyQyuwERNhHETfPtqx+qIIAxXI7FO700IxnwI2mPsdguFM6M31o5NqDOzOkCVqgLOw2sHjUYjZFuV/GvDg4Pr5xYMH2/rgDQabvKvWqHEte36cvqaGrosKwQLokZbM0qNugew9Jflu70EyWk9RzADOkKrE+1si24pMTo4u+/haXolcc=", "project_id": "a17a61c0334a4b31a131b89775ad0e6e", "devices": []}

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     

    NOTICE: This electronic mail message and any files transmitted with it are intended
    exclusively for the individual or entity to which it is addressed. The message,
    together with any attachment, may contain confidential and/or privileged information.
    Any unauthorized review, use, printing, saving, copying, disclosure or distribution
    is strictly prohibited. If you have received this message in error, please
    immediately advise the sender by reply email and delete all copies.






  • 13.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Mon May 23, 2022 02:00 PM

    Sanket, any update as to what may be missing in the AIX download?

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     






  • 14.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Fri August 05, 2022 01:09 PM

    I updated to the latest cloud.init and have the same issue. Its going out and getting a hostname from DNS that exists and assigning it to the partition. Cloud.init is not using the powerVC entered hostname it is over riding it with a hostname it finds in DNS.

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     

    NOTICE: This electronic mail message and any files transmitted with it are intended
    exclusively for the individual or entity to which it is addressed. The message,
    together with any attachment, may contain confidential and/or privileged information.
    Any unauthorized review, use, printing, saving, copying, disclosure or distribution
    is strictly prohibited. If you have received this message in error, please
    immediately advise the sender by reply email and delete all copies.






  • 15.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Tue August 09, 2022 12:44 AM
    Hi Karen, 
    From where did you updated cloud-init and what version ?

    ------------------------------
    SANKET RATHI
    ------------------------------



  • 16.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Thu August 11, 2022 04:55 PM

    From IBM toolbox

    https://www.ibm.com/support/pages/aix-toolbox-open-source-software-downloads-alpha

    cloud-init 0.7.5-4.4

    I loaded aix 7.2 clean install then loaded up everything needed for cloud-init 0.7.5-4.4

    When i deployed a partition i gave it the name in powerVC smocldtstdep1

    It is correct on the powerVC view when i logged into the partition the hostname was incorrect:

     

    The hostname set on the partition was

     

    Smolab423pmdeploytst1 a very old deleted partition which name is still in our DNS.

    It is looking at DNS and if it finds some old name in DNS it is assigning it to the partition and not assigning it the name we gave it.

     

    I took out the one line to not keep the hostname:

    This is my cloud.cfg.

    I have tested and tested with various scenarios and since the powerVC 2.0.1.1 update from 1.4.4 this has been the problem.

    Our systems are registered in DNS old name can remain and now PowerVC deploy cloud.init is looking in DNS when it should not be.

     

    # pwd

    /opt/freeware/etc/cloud

    # cat cloud.cfg

    # The top level settings are used as module

    # and system configuration.

     

    # A set of users which may be applied and/or used by various modules

    # when a 'default' entry is found it will reference the 'default_user'

    # from the distro configuration specified below

    users:

       - default

     

    # If this is set, 'root' will not be able to ssh in and they

    # will get a message to login instead as the above $user (ubuntu)

    disable_root: false

     

    # Allow SSH password authorization

    ssh_pwauth: true

     

    # Delete existing SSH host keys

    ssh_deletekeys: true

     

    # Regen rsa and dsa host keys

    ssh_genkeytypes: ['rsa', 'dsa']

     

    # This will cause the set+update hostname module to not operate (if true)

    preserve_hostname: false

     

    datasource_list: ['ConfigDrive']

     

    # Example datasource config

    # datasource:

    #    Ec2:

    #      metadata_urls: [ 'blah.com' ]

    #      timeout: 5 # (defaults to 50 seconds)

    #      max_wait: 10 # (defaults to 120 seconds)

     

    # The modules that run in the 'init' stage

    cloud_init_modules:

    - migrator

    - seed_random

    - bootcmd

    - write-files

    - set_hostname

    - update_etc_hosts

    - ca-certs

    - rsyslog

    - users-groups

    - ssh

    - restore-volume-groups

    - set-multipath-hcheck-interval

    - update-bootlist

    - reset-rmc

     

    # The modules that run in the 'config' stage

    cloud_config_modules:

    # Emit the cloud config ready event

    # this can be used by upstart jobs for 'start on cloud-config'.

    - emit_upstart

    - disk_setup

    - mounts

    - ssh-import-id

    - locale

    - set-passwords

    - package-update-upgrade-install

    - landscape

    - timezone

    - puppet

    - chef

    - salt-minion

    - mcollective

    - disable-ec2-metadata

    - runcmd

    - byobu

     

    # The modules that run in the 'final' stage

    cloud_final_modules:

    - rightscale_userdata

    - scripts-vendor

    - scripts-per-once

    - scripts-per-boot

    - scripts-per-instance

    - scripts-user

    - ssh-authkey-fingerprints

    - keys-to-console

    - phone-home

    - final-message

    - power-state-change

     

    # System and/or distro specific settings

    # (not accessible to handlers/transforms)

    system_info:

       # This will affect which distro class gets used

       distro: aix

       # Default user name + that default users groups (if added/used)

       default_user:

         name: root

         lock_passwd: false

       # Other config here will be given to the distro class and/or path classes

       paths:

          cloud_dir: /opt/freeware/var/lib/cloud/

          templates_dir: /opt/freeware/etc/cloud/templates/

          upstart_dir: /etc/rc.d/init.d/

       ssh_svcname: ssh

     

     

     

    Karen Van Gogh |  Sys/Ntwk Admstr,Advsry | Corporate Systems – POWER Systems Administration | Jack Henry & Associates, Inc.®

    8985 Balboa Ave  | San Diego CA 92123 | Ph. 619-682-3325 |internal extension  x763325 | CELL: 619-318-0416 |  kvangogh@jackhenry.com

     






  • 17.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Tue May 17, 2022 01:42 PM

    Updated to the latest level and retested with the same results: I had a partition that it named   smocommvaultlab .. I entered the name: smolabibmtst51122p6

    I mounted the cd0 to /mnt and looked around in the directories and in the meta-data.json i do see the correct name in the files so I am not sure where its picking the incorrect name.

     

    #/opt/freeware/bin/cloud-init --version

    cloud-init 0.7.5

    root@smocommvaultlab #yum update cloud-init

    Setting up Update Process

    No Packages marked for Update



    ------------------------------
    Karen Van Gogh
    Jack Henry and Associates
    kvangogh@jackhenry.com
    ------------------------------



  • 18.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Wed May 11, 2022 09:14 AM
    attempt to upload files failed

    ------------------------------
    Karen Van Gogh
    Jack Henry and Associates
    kvangogh@jackhenry.com
    ------------------------------



  • 19.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Wed May 11, 2022 09:32 AM
    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 testforibm
    2022-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_hosts
    2022-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
    ------------------------------



  • 20.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Fri May 13, 2022 10:56 PM
    Hello, thanks for the log. It is helpful. I can see it contains the several runs of cloud-init.  The init run on May 11, its cc_set_hostname was found and used to change the hostname, but it is not the one that was mentioned in post#11. not sure if this is the right log. just want to point out.
    .......
    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 testforibm
    2022-05-11 03:19:01,400 - util.py[DEBUG]: Running command ['hostname', u'testforibm'] with allowed return codes [0] (shell=False, capture=True)
    .....

    cc_set_hostname gets the hostname from cfg, which reads hostname from metadata. The metadata is provide by powerVC. If cfg does not contain hostname, it will fall back to data from cloud. In this case the hostname was read from cfg according to the log,  please check if metadata was updated properly by PowerVC.

    ------------------------------
    Rae Yang
    ------------------------------



  • 21.  RE: PowerVC Deploy cloud-init cloud.cfg incorrect hostname assigned to partition

    Posted Mon March 04, 2024 07:52 PM

    this is still occurring at 2.1.1.1 I have a case open with powervc support since last year they are still looking into this problem



    ------------------------------
    Karen Van Gogh
    Jack Henry and Associates
    kvangogh@jackhenry.com
    ------------------------------