search

vmware / photon

Minimal Linux container host
https://vmware.github.io/photon
Other
3.05k stars 696 forks source link

cloud-init network version 1 not getting applied #1053

Closed JanHolger closed 4 years ago

JanHolger commented 4 years ago

Hi again (:

I made my installation cloud-init ready now, but i have a problem with the network configuration. ProxMox is generating the seed iso with a network-config version 1 (https://prnt.sc/uvkt8b) which seems to be fine and i'm already using it with different systems (Debian, Ubuntu, CentOS).

In photon it doesn't seem to catch the network-config though. I also checked cloud-init-output.log and couldn't find any real errors https://prnt.sc/uvkvb5. I deleted /etc/cloud/cloud.cfg.d/99-disable-networking-config.cfg as this file seems to disable network configuration.

I hope that it's just some stupid mistake on my side again but I couldn't find anything on static networking with cloud-init in the docs.

Thanks in advance!

JanHolger commented 4 years ago

Here is my cloud.cfg in case that's important:

users:
  - default

disable_root: false

disable_vmware_customization: true

preserve_hostname: false

datasource_list: [
    NoCloud,
    ConfigDrive
    ]

cloud_init_modules:
 - migrator
 - seed_random
 - bootcmd
 - write-files
 - growpart
 - resizefs
 - disk_setup
 - mounts
 - set_hostname
 - update_hostname
 - update_etc_hosts
 - rsyslog
 - users-groups
 - ssh

cloud_config_modules:
 - ssh-import-id
 - set-passwords
 - yum-add-repo
 - ntp
 - timezone
 - runcmd
 - disable-ec2-metadata

unverified_modules: ['yum-add-repo', 'ntp']

cloud_final_modules:
 - package-update-upgrade-install
 - 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_info:
   distro: photon
   default_user:
     name: cloud-init
     lock_passwd: True
     gecos: PhotonOS
     groups: [adm, audio, cdrom, dialout, dip, floppy, netdev, plugdev, sudo]
     sudo: ["ALL=(ALL) NOPASSWD:ALL"]
     shell: /bin/bash
   paths:
      cloud_dir: /var/lib/cloud/
      templates_dir: /etc/cloud/templates/
   ssh_svcname: sshd
dcasota commented 4 years ago

@JanHolger The network specified should connect to the internet. The "couldn't resolve host name" indicates that the ipaddress acquired does not. In cloud-init it may help to configure network settings with LinkLocalAddressing=no. See #800. There is a related blog post as well.

ssahani commented 4 years ago

I have not tested with v1. Can you please test with v2 https://github.com/vmware/photon/blob/master/SPECS/cloud-init/photon-distro.patch#L76 . https://cloudinit.readthedocs.io/en/latest/topics/network-config-format-v2.html

We added those .

JanHolger commented 4 years ago

@dcasota It's an internal network and it would have internet connection if the gateway route would be configured, but cloud-init doesn't configure any networking so it obviously can't connect to the internet.

@ssahani Unfortunately ProxMox only supports NoCloud networking v1 and the official cloud-init docs say that v1 is compatible. It's also working fine on other systems but i guess none of these systems use systemd-networkd (Debian/Ubuntu is ENI and CentOS is sysconfig). Is there anything i need to configure in the vm to get v1 working?

dcasota commented 4 years ago

@JanHolger ‚disable_vmware_customization: true‘ is set because of the qemu (+proxmox v1) scenario right?

JanHolger commented 4 years ago

@dcasota yes i've read the docs and it said that i should disable it in a non-vSphere environment. Anything wrong about that?

JanHolger commented 4 years ago

I guess i could simply edit the python function to detect whether it's v1 or v2 and properly read and write the config file? If yes where is this file sitting in the system?

sshedi commented 4 years ago

@JanHolger Please provide the cloud-init logs from /valr/log/. Also need your network configuration details (i.e the input that's fed to cloud-init)

sshedi commented 4 years ago

I have few more suggestions for you:

in your /etc/cloud/cloud.cfg; add VMwareGuestInfo

datasource_list: [
    NoCloud,
    VMwareGuestInfo,
    ConfigDrive
    ]

Reboot and retry your things.

If this doesn't work; Then do the following and try (don't remove VMwareGuestInfo from cloud.cfg)


$ vmware-rpctool "info-set guestinfo.metadata $(cat <your yaml cfg file>)"

And give it a run.

JanHolger commented 4 years ago

Here is cloud-init.log and it definitely detects the network-config but it doesn't write the .network files because from what i've seen in the patch file you only support v2 syntax atm.

2020-10-08 15:27:24,558 - util.py[DEBUG]: Cloud-init v. 19.4 running 'init' at Thu, 08 Oct 2020 15:27:24 +0000. Up 126.59 seconds.
2020-10-08 15:27:24,558 - main.py[DEBUG]: No kernel command line url found.
2020-10-08 15:27:24,558 - main.py[DEBUG]: Closing stdin.
2020-10-08 15:27:24,559 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-10-08 15:27:24,560 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:16
2020-10-08 15:27:24,560 - util.py[DEBUG]: Running command ['ip', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,566 - util.py[DEBUG]: Running command ['ip', '-o', 'route', 'list'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,568 - util.py[DEBUG]: Running command ['ip', '--oneline', '-6', 'route', 'list', 'table', 'all'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-10-08 15:27:24,571 - main.py[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2020-10-08 15:27:24,572 - main.py[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early.
2020-10-08 15:27:24,572 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust]
2020-10-08 15:27:24,572 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-10-08 15:27:24,572 - util.py[DEBUG]: Read 5514 bytes from /var/lib/cloud/instance/obj.pkl
2020-10-08 15:27:24,575 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
2020-10-08 15:27:24,575 - util.py[DEBUG]: Read 41 bytes from /run/cloud-init/.instance-id
2020-10-08 15:27:24,575 - stages.py[DEBUG]: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-10-08 15:27:24,575 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-10-08 15:27:24,575 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-08 15:27:24,576 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-08 15:27:24,576 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,587 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-08 15:27:24,587 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-08 15:27:24,587 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,592 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-08 15:27:24,592 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-08 15:27:24,592 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,593 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,593 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-08 15:27:24,593 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-10-08 15:27:24,593 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8'
2020-10-08 15:27:24,594 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource (quiet=False)
2020-10-08 15:27:24,594 - util.py[DEBUG]: Read 65 bytes from /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource
2020-10-08 15:27:24,594 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource - wb: [644] 65 bytes
2020-10-08 15:27:24,594 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 65 bytes
2020-10-08 15:27:24,595 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-10-08 15:27:24,595 - util.py[DEBUG]: Read 41 bytes from /var/lib/cloud/data/instance-id
2020-10-08 15:27:24,595 - stages.py[DEBUG]: previous iid found to be 3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8
2020-10-08 15:27:24,595 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 41 bytes
2020-10-08 15:27:24,595 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 41 bytes
2020-10-08 15:27:24,596 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 41 bytes
2020-10-08 15:27:24,596 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 5589 bytes
2020-10-08 15:27:24,597 - main.py[DEBUG]: [net] init will now be targeting instance id: 3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8. new=False
2020-10-08 15:27:24,597 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-08 15:27:24,597 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-08 15:27:24,597 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,607 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-08 15:27:24,607 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-08 15:27:24,608 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,612 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-08 15:27:24,612 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-08 15:27:24,612 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,613 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,613 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-08 15:27:24,614 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-10-08 15:27:24,614 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-10-08 15:27:24,614 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-10-08 15:27:24,614 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2020-10-08 15:27:24,615 - __init__.py[DEBUG]: Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net] not updated for events: System boot
2020-10-08 15:27:24,615 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update on 'System boot' event
2020-10-08 15:27:24,615 - stages.py[DEBUG]: applying net config names for {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '42:e8:c2:75:78:71', 'subnets': [{'type': 'static', 'address': '10.16.33.5', 'netmask': '255.255.0.0', 'gateway': '10.16.0.1'}]}, {'type': 'nameserver', 'address': ['8.8.8.8']}]}
2020-10-08 15:27:24,615 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-08 15:27:24,615 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-10-08 15:27:24,615 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2020-10-08 15:27:24,615 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type
2020-10-08 15:27:24,616 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent
2020-10-08 15:27:24,616 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-10-08 15:27:24,616 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type
2020-10-08 15:27:24,616 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent
2020-10-08 15:27:24,616 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2020-10-08 15:27:24,616 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-10-08 15:27:24,616 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2020-10-08 15:27:24,617 - util.py[DEBUG]: Reading from /sys/class/net/lo/operstate (quiet=False)
2020-10-08 15:27:24,617 - util.py[DEBUG]: Read 8 bytes from /sys/class/net/lo/operstate
2020-10-08 15:27:24,617 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False)
2020-10-08 15:27:24,617 - util.py[DEBUG]: Read 5 bytes from /sys/class/net/eth0/operstate
2020-10-08 15:27:24,617 - util.py[DEBUG]: Running command ['ip', '-6', 'addr', 'show', 'permanent', 'scope', 'global'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,619 - util.py[DEBUG]: Running command ['ip', '-4', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,621 - __init__.py[DEBUG]: no work necessary for renaming of [['42:e8:c2:75:78:71', 'eth0', 'virtio_net', '0x0001']]
2020-10-08 15:27:24,621 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource
2020-10-08 15:27:24,621 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource
2020-10-08 15:27:24,621 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/user-data.txt - wb: [600] 842 bytes
2020-10-08 15:27:24,622 - util.py[DEBUG]: Attempting to load yaml from string of length 842 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,627 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/user-data.txt.i - wb: [600] 1147 bytes
2020-10-08 15:27:24,627 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/vendor-data.txt - wb: [600] 0 bytes
2020-10-08 15:27:24,628 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/vendor-data.txt.i - wb: [600] 308 bytes
2020-10-08 15:27:24,629 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/consume_data - wb: [644] 24 bytes
2020-10-08 15:27:24,629 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/consume_data'>)
2020-10-08 15:27:24,629 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data
2020-10-08 15:27:24,631 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2020-10-08 15:27:24,631 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
2020-10-08 15:27:24,631 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
2020-10-08 15:27:24,631 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']]
2020-10-08 15:27:24,631 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
2020-10-08 15:27:24,632 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2020-10-08 15:27:24,632 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2020-10-08 15:27:24,632 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2020-10-08 15:27:24,632 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2020-10-08 15:27:24,632 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance
2020-10-08 15:27:24,632 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Type': 'text/cloud-config', 'Content-Disposition': 'attachment; filename="part-001"'}
2020-10-08 15:27:24,632 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance
2020-10-08 15:27:24,632 - util.py[DEBUG]: Attempting to load yaml from string of length 842 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,661 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])]
2020-10-08 15:27:24,661 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2020-10-08 15:27:24,663 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/cloud-config.txt - wb: [600] 882 bytes
2020-10-08 15:27:24,664 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2020-10-08 15:27:24,664 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2020-10-08 15:27:24,664 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2020-10-08 15:27:24,664 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance
2020-10-08 15:27:24,665 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data
2020-10-08 15:27:24,665 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data
2020-10-08 15:27:24,665 - stages.py[DEBUG]: no vendordata from datasource
2020-10-08 15:27:24,665 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data
2020-10-08 15:27:24,665 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-08 15:27:24,665 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-08 15:27:24,665 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,676 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-08 15:27:24,677 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-08 15:27:24,677 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,682 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-08 15:27:24,682 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-08 15:27:24,682 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,682 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,682 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-08 15:27:24,683 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-10-08 15:27:24,683 - util.py[DEBUG]: Read 882 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-10-08 15:27:24,683 - util.py[DEBUG]: Attempting to load yaml from string of length 882 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,686 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-10-08 15:27:24,686 - util.py[DEBUG]: Read 882 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-10-08 15:27:24,686 - util.py[DEBUG]: Attempting to load yaml from string of length 882 with allowed root types (<class 'dict'>,)
2020-10-08 15:27:24,692 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource
2020-10-08 15:27:24,693 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 8327 bytes
2020-10-08 15:27:24,694 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource
2020-10-08 15:27:24,694 - main.py[DEBUG]: no di_report found in config.
2020-10-08 15:27:24,717 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-08 15:27:24,717 - stages.py[DEBUG]: Running module migrator (<module 'cloudinit.config.cc_migrator' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_migrator.py'>) with frequency always
2020-10-08 15:27:24,718 - handlers.py[DEBUG]: start: init-network/config-migrator: running config-migrator with frequency always
2020-10-08 15:27:24,718 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0x7fd82721cf50>)
2020-10-08 15:27:24,719 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2020-10-08 15:27:24,719 - handlers.py[DEBUG]: finish: init-network/config-migrator: SUCCESS: config-migrator ran successfully
2020-10-08 15:27:24,720 - stages.py[DEBUG]: Running module seed_random (<module 'cloudinit.config.cc_seed_random' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_seed_random.py'>) with frequency once-per-instance
2020-10-08 15:27:24,720 - handlers.py[DEBUG]: start: init-network/config-seed_random: running config-seed_random with frequency once-per-instance
2020-10-08 15:27:24,720 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_seed_random - wb: [644] 24 bytes
2020-10-08 15:27:24,720 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_seed_random'>)
2020-10-08 15:27:24,721 - cc_seed_random.py[DEBUG]: no command provided
2020-10-08 15:27:24,721 - handlers.py[DEBUG]: finish: init-network/config-seed_random: SUCCESS: config-seed_random ran successfully
2020-10-08 15:27:24,721 - stages.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_bootcmd.py'>) with frequency always
2020-10-08 15:27:24,721 - handlers.py[DEBUG]: start: init-network/config-bootcmd: running config-bootcmd with frequency always
2020-10-08 15:27:24,721 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x7fd82721c310>)
2020-10-08 15:27:24,721 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2020-10-08 15:27:24,721 - handlers.py[DEBUG]: finish: init-network/config-bootcmd: SUCCESS: config-bootcmd ran successfully
2020-10-08 15:27:24,721 - stages.py[DEBUG]: Running module write-files (<module 'cloudinit.config.cc_write_files' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_write_files.py'>) with frequency once-per-instance
2020-10-08 15:27:24,721 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance
2020-10-08 15:27:24,721 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_write_files - wb: [644] 24 bytes
2020-10-08 15:27:24,722 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_write_files'>)
2020-10-08 15:27:24,722 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2020-10-08 15:27:24,722 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files ran successfully
2020-10-08 15:27:24,722 - stages.py[DEBUG]: Running module growpart (<module 'cloudinit.config.cc_growpart' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_growpart.py'>) with frequency always
2020-10-08 15:27:24,722 - handlers.py[DEBUG]: start: init-network/config-growpart: running config-growpart with frequency always
2020-10-08 15:27:24,722 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x7fd827264ed0>)
2020-10-08 15:27:24,722 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg.  Using default: {'mode': 'auto', 'devices': ['/'], 'ignore_growroot_disabled': False}
2020-10-08 15:27:24,723 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,725 - cc_growpart.py[DEBUG]: growpart unable to find resizer for 'auto': No resizers available
2020-10-08 15:27:24,725 - handlers.py[DEBUG]: finish: init-network/config-growpart: SUCCESS: config-growpart ran successfully
2020-10-08 15:27:24,725 - stages.py[DEBUG]: Running module resizefs (<module 'cloudinit.config.cc_resizefs' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_resizefs.py'>) with frequency always
2020-10-08 15:27:24,725 - handlers.py[DEBUG]: start: init-network/config-resizefs: running config-resizefs with frequency always
2020-10-08 15:27:24,726 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x7fd82721c650>)
2020-10-08 15:27:24,741 - util.py[DEBUG]: Reading from /proc/423/mountinfo (quiet=False)
2020-10-08 15:27:24,741 - util.py[DEBUG]: Read 2678 bytes from /proc/423/mountinfo
2020-10-08 15:27:24,741 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/sda3 mnt_point=/ path=/
2020-10-08 15:27:24,741 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,745 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,746 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,747 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-10-08 15:27:24,747 - util.py[DEBUG]: Read 58 bytes from /proc/1/environ
2020-10-08 15:27:24,747 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-10-08 15:27:24,747 - util.py[DEBUG]: Read 1286 bytes from /proc/self/status
2020-10-08 15:27:24,748 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/sda3
2020-10-08 15:27:24,748 - util.py[DEBUG]: Running command ('resize2fs', '/dev/sda3') with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,762 - util.py[DEBUG]: Resizing took 0.015 seconds
2020-10-08 15:27:24,763 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True)
2020-10-08 15:27:24,763 - handlers.py[DEBUG]: finish: init-network/config-resizefs: SUCCESS: config-resizefs ran successfully
2020-10-08 15:27:24,763 - stages.py[DEBUG]: Running module disk_setup (<module 'cloudinit.config.cc_disk_setup' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_disk_setup.py'>) with frequency once-per-instance
2020-10-08 15:27:24,763 - handlers.py[DEBUG]: start: init-network/config-disk_setup: running config-disk_setup with frequency once-per-instance
2020-10-08 15:27:24,764 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_disk_setup - wb: [644] 24 bytes
2020-10-08 15:27:24,765 - helpers.py[DEBUG]: Running config-disk_setup using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_disk_setup'>)
2020-10-08 15:27:24,765 - handlers.py[DEBUG]: finish: init-network/config-disk_setup: SUCCESS: config-disk_setup ran successfully
2020-10-08 15:27:24,765 - stages.py[DEBUG]: Running module mounts (<module 'cloudinit.config.cc_mounts' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_mounts.py'>) with frequency once-per-instance
2020-10-08 15:27:24,765 - handlers.py[DEBUG]: start: init-network/config-mounts: running config-mounts with frequency once-per-instance
2020-10-08 15:27:24,765 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_mounts - wb: [644] 23 bytes
2020-10-08 15:27:24,766 - helpers.py[DEBUG]: Running config-mounts using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_mounts'>)
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: mounts configuration is []
2020-10-08 15:27:24,766 - util.py[DEBUG]: Reading from /etc/fstab (quiet=False)
2020-10-08 15:27:24,766 - util.py[DEBUG]: Read 257 bytes from /etc/fstab
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: changed default device ephemeral0 => None
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount ephemeral0
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: Attempting to determine the real name of swap
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: changed default device swap => None
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount swap
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: no need to setup swap
2020-10-08 15:27:24,766 - cc_mounts.py[DEBUG]: No modifications to fstab needed
2020-10-08 15:27:24,766 - handlers.py[DEBUG]: finish: init-network/config-mounts: SUCCESS: config-mounts ran successfully
2020-10-08 15:27:24,766 - stages.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_set_hostname.py'>) with frequency once-per-instance
2020-10-08 15:27:24,767 - handlers.py[DEBUG]: start: init-network/config-set_hostname: running config-set_hostname with frequency once-per-instance
2020-10-08 15:27:24,767 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_hostname - wb: [644] 23 bytes
2020-10-08 15:27:24,767 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_hostname'>)
2020-10-08 15:27:24,767 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-10-08 15:27:24,767 - util.py[DEBUG]: Read 645 bytes from /etc/hosts
2020-10-08 15:27:24,767 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False)
2020-10-08 15:27:24,771 - util.py[DEBUG]: Read 49 bytes from /var/lib/cloud/data/set-hostname
2020-10-08 15:27:24,771 - cc_set_hostname.py[DEBUG]: Setting the hostname to PhotonOS (PhotonOS3)
2020-10-08 15:27:24,771 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2020-10-08 15:27:24,771 - util.py[DEBUG]: Read 9 bytes from /etc/hostname
2020-10-08 15:27:24,771 - util.py[DEBUG]: Writing to /etc/hostname - wb: [644] 10 bytes
2020-10-08 15:27:24,772 - __init__.py[DEBUG]: Non-persistently setting the system hostname to PhotonOS3
2020-10-08 15:27:24,772 - util.py[DEBUG]: Running command ['hostname', 'PhotonOS3'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,777 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/set-hostname (via temporary file /var/lib/cloud/data/tmpb199fk04) - w: [644] 50 bytes/chars
2020-10-08 15:27:24,777 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: SUCCESS: config-set_hostname ran successfully
2020-10-08 15:27:24,777 - stages.py[DEBUG]: Running module update_hostname (<module 'cloudinit.config.cc_update_hostname' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_update_hostname.py'>) with frequency always
2020-10-08 15:27:24,777 - handlers.py[DEBUG]: start: init-network/config-update_hostname: running config-update_hostname with frequency always
2020-10-08 15:27:24,778 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x7fd82719bd50>)
2020-10-08 15:27:24,778 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-10-08 15:27:24,778 - util.py[DEBUG]: Read 645 bytes from /etc/hosts
2020-10-08 15:27:24,778 - cc_update_hostname.py[DEBUG]: Updating hostname to PhotonOS3 (PhotonOS3)
2020-10-08 15:27:24,778 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False)
2020-10-08 15:27:24,779 - util.py[DEBUG]: Read 9 bytes from /var/lib/cloud/data/previous-hostname
2020-10-08 15:27:24,779 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2020-10-08 15:27:24,779 - util.py[DEBUG]: Read 10 bytes from /etc/hostname
2020-10-08 15:27:24,779 - __init__.py[INFO]: /var/lib/cloud/data/previous-hostname differs from /etc/hostname, assuming user maintained hostname.
2020-10-08 15:27:24,779 - handlers.py[DEBUG]: finish: init-network/config-update_hostname: SUCCESS: config-update_hostname ran successfully
2020-10-08 15:27:24,779 - stages.py[DEBUG]: Running module update_etc_hosts (<module 'cloudinit.config.cc_update_etc_hosts' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_update_etc_hosts.py'>) with frequency always
2020-10-08 15:27:24,780 - handlers.py[DEBUG]: start: init-network/config-update_etc_hosts: running config-update_etc_hosts with frequency always
2020-10-08 15:27:24,780 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x7fd8271a6150>)
2020-10-08 15:27:24,780 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-10-08 15:27:24,780 - util.py[DEBUG]: Read 645 bytes from /etc/hosts
2020-10-08 15:27:24,781 - util.py[DEBUG]: Reading from /etc/cloud/templates/hosts.photon.tmpl (quiet=False)
2020-10-08 15:27:24,782 - util.py[DEBUG]: Read 875 bytes from /etc/cloud/templates/hosts.photon.tmpl
2020-10-08 15:27:24,782 - templater.py[DEBUG]: Rendering content of '/etc/cloud/templates/hosts.photon.tmpl' using renderer jinja
2020-10-08 15:27:24,786 - util.py[DEBUG]: Writing to /etc/hosts - wb: [644] 649 bytes
2020-10-08 15:27:24,787 - handlers.py[DEBUG]: finish: init-network/config-update_etc_hosts: SUCCESS: config-update_etc_hosts ran successfully
2020-10-08 15:27:24,787 - stages.py[DEBUG]: Running module rsyslog (<module 'cloudinit.config.cc_rsyslog' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_rsyslog.py'>) with frequency once-per-instance
2020-10-08 15:27:24,787 - handlers.py[DEBUG]: start: init-network/config-rsyslog: running config-rsyslog with frequency once-per-instance
2020-10-08 15:27:24,788 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_rsyslog - wb: [644] 24 bytes
2020-10-08 15:27:24,788 - helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_rsyslog'>)
2020-10-08 15:27:24,788 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
2020-10-08 15:27:24,788 - handlers.py[DEBUG]: finish: init-network/config-rsyslog: SUCCESS: config-rsyslog ran successfully
2020-10-08 15:27:24,788 - stages.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_users_groups.py'>) with frequency once-per-instance
2020-10-08 15:27:24,789 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance
2020-10-08 15:27:24,789 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_users_groups - wb: [644] 23 bytes
2020-10-08 15:27:24,789 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_users_groups'>)
2020-10-08 15:27:24,790 - __init__.py[INFO]: User root already exists, skipping.
2020-10-08 15:27:24,790 - util.py[DEBUG]: Running command ['passwd', '-l', 'root'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,801 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False)
2020-10-08 15:27:24,802 - util.py[DEBUG]: Read 3218 bytes from /etc/sudoers
2020-10-08 15:27:24,804 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - ab: [None] 51 bytes
2020-10-08 15:27:24,806 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups ran successfully
2020-10-08 15:27:24,806 - stages.py[DEBUG]: Running module ssh (<module 'cloudinit.config.cc_ssh' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_ssh.py'>) with frequency once-per-instance
2020-10-08 15:27:24,806 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance
2020-10-08 15:27:24,806 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh - wb: [644] 24 bytes
2020-10-08 15:27:24,807 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh'>)
2020-10-08 15:27:24,807 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key.pub
2020-10-08 15:27:24,807 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key
2020-10-08 15:27:24,808 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key
2020-10-08 15:27:24,808 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key.pub
2020-10-08 15:27:24,808 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key.pub
2020-10-08 15:27:24,808 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key
2020-10-08 15:27:24,808 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key.pub
2020-10-08 15:27:24,808 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key
2020-10-08 15:27:24,808 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,917 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'dsa', '-N', '', '-f', '/etc/ssh/ssh_host_dsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,978 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ecdsa', '-N', '', '-f', '/etc/ssh/ssh_host_ecdsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:24,990 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ed25519', '-N', '', '-f', '/etc/ssh/ssh_host_ed25519_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:25,005 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ecdsa_key.pub (quiet=False)
2020-10-08 15:27:25,005 - util.py[DEBUG]: Read 176 bytes from /etc/ssh/ssh_host_ecdsa_key.pub
2020-10-08 15:27:25,005 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_rsa_key.pub (quiet=False)
2020-10-08 15:27:25,006 - util.py[DEBUG]: Read 396 bytes from /etc/ssh/ssh_host_rsa_key.pub
2020-10-08 15:27:25,006 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ed25519_key.pub (quiet=False)
2020-10-08 15:27:25,006 - util.py[DEBUG]: Read 96 bytes from /etc/ssh/ssh_host_ed25519_key.pub
2020-10-08 15:27:25,007 - util.py[DEBUG]: Changing the ownership of /root/.ssh to 0:0
2020-10-08 15:27:25,007 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-10-08 15:27:25,009 - util.py[DEBUG]: Read 3265 bytes from /etc/ssh/sshd_config
2020-10-08 15:27:25,010 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 564 bytes
2020-10-08 15:27:25,010 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2020-10-08 15:27:25,010 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-10-08 15:27:25,011 - util.py[DEBUG]: Read 3265 bytes from /etc/ssh/sshd_config
2020-10-08 15:27:25,011 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False)
2020-10-08 15:27:25,011 - util.py[DEBUG]: Read 564 bytes from /root/.ssh/authorized_keys
2020-10-08 15:27:25,011 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 564 bytes
2020-10-08 15:27:25,012 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2020-10-08 15:27:25,012 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh ran successfully
2020-10-08 15:27:25,012 - main.py[DEBUG]: Ran 14 modules with 0 failures
2020-10-08 15:27:25,013 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpt_ucv1tc) - w: [644] 544 bytes/chars
2020-10-08 15:27:25,013 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-08 15:27:25,013 - util.py[DEBUG]: Read 14 bytes from /proc/uptime
2020-10-08 15:27:25,013 - util.py[DEBUG]: cloud-init mode 'init' took 0.483 seconds (0.49)
2020-10-08 15:27:25,013 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources
2020-10-08 15:27:25,571 - util.py[DEBUG]: Cloud-init v. 19.4 running 'modules:config' at Thu, 08 Oct 2020 15:27:25 +0000. Up 127.56 seconds.
2020-10-08 15:27:25,585 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-08 15:27:25,585 - stages.py[INFO]: Skipping modules 'ssh-import-id' because they are not verified on distro 'photon'.  To run anyway, add them to 'unverified_modules' in config.
2020-10-08 15:27:25,585 - stages.py[INFO]: running unverified_modules: 'yum-add-repo, ntp'
2020-10-08 15:27:25,585 - stages.py[DEBUG]: Running module set-passwords (<module 'cloudinit.config.cc_set_passwords' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_set_passwords.py'>) with frequency once-per-instance
2020-10-08 15:27:25,586 - handlers.py[DEBUG]: start: modules-config/config-set-passwords: running config-set-passwords with frequency once-per-instance
2020-10-08 15:27:25,586 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_passwords - wb: [644] 24 bytes
2020-10-08 15:27:25,586 - helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_passwords'>)
2020-10-08 15:27:25,587 - cc_set_passwords.py[DEBUG]: Setting hashed password for ['root']:
2020-10-08 15:27:25,588 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-10-08 15:27:25,588 - util.py[DEBUG]: Read 219 bytes from /etc/os-release
2020-10-08 15:27:25,588 - util.py[DEBUG]: Running command ['chpasswd', '-e'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:25,616 - cc_set_passwords.py[DEBUG]: Leaving ssh config 'PasswordAuthentication' unchanged. ssh_pwauth=None
2020-10-08 15:27:25,616 - handlers.py[DEBUG]: finish: modules-config/config-set-passwords: SUCCESS: config-set-passwords ran successfully
2020-10-08 15:27:25,616 - stages.py[DEBUG]: Running module yum-add-repo (<module 'cloudinit.config.cc_yum_add_repo' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_yum_add_repo.py'>) with frequency once-per-instance
2020-10-08 15:27:25,617 - handlers.py[DEBUG]: start: modules-config/config-yum-add-repo: running config-yum-add-repo with frequency once-per-instance
2020-10-08 15:27:25,617 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_yum_add_repo - wb: [644] 24 bytes
2020-10-08 15:27:25,618 - helpers.py[DEBUG]: Running config-yum-add-repo using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_yum_add_repo'>)
2020-10-08 15:27:25,618 - cc_yum_add_repo.py[DEBUG]: Skipping module named yum-add-repo, no 'yum_repos' configuration found
2020-10-08 15:27:25,618 - handlers.py[DEBUG]: finish: modules-config/config-yum-add-repo: SUCCESS: config-yum-add-repo ran successfully
2020-10-08 15:27:25,618 - stages.py[DEBUG]: Running module ntp (<module 'cloudinit.config.cc_ntp' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_ntp.py'>) with frequency once-per-instance
2020-10-08 15:27:25,618 - handlers.py[DEBUG]: start: modules-config/config-ntp: running config-ntp with frequency once-per-instance
2020-10-08 15:27:25,618 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ntp - wb: [644] 24 bytes
2020-10-08 15:27:25,619 - helpers.py[DEBUG]: Running config-ntp using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ntp'>)
2020-10-08 15:27:25,619 - cc_ntp.py[DEBUG]: Skipping module named ntp, not present or disabled by cfg
2020-10-08 15:27:25,619 - handlers.py[DEBUG]: finish: modules-config/config-ntp: SUCCESS: config-ntp ran successfully
2020-10-08 15:27:25,619 - stages.py[DEBUG]: Running module timezone (<module 'cloudinit.config.cc_timezone' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_timezone.py'>) with frequency once-per-instance
2020-10-08 15:27:25,619 - handlers.py[DEBUG]: start: modules-config/config-timezone: running config-timezone with frequency once-per-instance
2020-10-08 15:27:25,619 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_timezone - wb: [644] 23 bytes
2020-10-08 15:27:25,619 - helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_timezone'>)
2020-10-08 15:27:25,620 - cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified
2020-10-08 15:27:25,620 - handlers.py[DEBUG]: finish: modules-config/config-timezone: SUCCESS: config-timezone ran successfully
2020-10-08 15:27:25,620 - stages.py[DEBUG]: Running module runcmd (<module 'cloudinit.config.cc_runcmd' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_runcmd.py'>) with frequency once-per-instance
2020-10-08 15:27:25,620 - handlers.py[DEBUG]: start: modules-config/config-runcmd: running config-runcmd with frequency once-per-instance
2020-10-08 15:27:25,620 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_runcmd - wb: [644] 24 bytes
2020-10-08 15:27:25,620 - helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_runcmd'>)
2020-10-08 15:27:25,620 - cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration
2020-10-08 15:27:25,621 - handlers.py[DEBUG]: finish: modules-config/config-runcmd: SUCCESS: config-runcmd ran successfully
2020-10-08 15:27:25,621 - stages.py[DEBUG]: Running module disable-ec2-metadata (<module 'cloudinit.config.cc_disable_ec2_metadata' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_disable_ec2_metadata.py'>) with frequency always
2020-10-08 15:27:25,621 - handlers.py[DEBUG]: start: modules-config/config-disable-ec2-metadata: running config-disable-ec2-metadata with frequency always
2020-10-08 15:27:25,621 - helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock (<cloudinit.helpers.DummyLock object at 0x7f2218afba10>)
2020-10-08 15:27:25,621 - cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled
2020-10-08 15:27:25,621 - handlers.py[DEBUG]: finish: modules-config/config-disable-ec2-metadata: SUCCESS: config-disable-ec2-metadata ran successfully
2020-10-08 15:27:25,621 - main.py[DEBUG]: Ran 6 modules with 0 failures
2020-10-08 15:27:25,621 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpzrrent_1) - w: [644] 571 bytes/chars
2020-10-08 15:27:25,622 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-08 15:27:25,622 - util.py[DEBUG]: Read 14 bytes from /proc/uptime
2020-10-08 15:27:25,622 - util.py[DEBUG]: cloud-init mode 'modules' took 0.113 seconds (0.12)
2020-10-08 15:27:25,622 - handlers.py[DEBUG]: finish: modules-config: SUCCESS: running modules for config
2020-10-08 15:27:26,118 - util.py[DEBUG]: Cloud-init v. 19.4 running 'modules:final' at Thu, 08 Oct 2020 15:27:26 +0000. Up 128.11 seconds.
2020-10-08 15:27:26,132 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-08 15:27:26,133 - stages.py[DEBUG]: Running module package-update-upgrade-install (<module 'cloudinit.config.cc_package_update_upgrade_install' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_package_update_upgrade_install.py'>) with frequency once-per-instance
2020-10-08 15:27:26,133 - handlers.py[DEBUG]: start: modules-final/config-package-update-upgrade-install: running config-package-update-upgrade-install with frequency once-per-instance
2020-10-08 15:27:26,133 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_package_update_upgrade_install - wb: [644] 24 bytes
2020-10-08 15:27:26,134 - helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_package_update_upgrade_install'>)
2020-10-08 15:27:26,134 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/update_sources - wb: [644] 24 bytes
2020-10-08 15:27:26,136 - helpers.py[DEBUG]: Running update-sources using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/update_sources'>)
2020-10-08 15:27:26,136 - util.py[DEBUG]: Running command ['tdnf', '-y', 'makecache'] with allowed return codes [0] (shell=False, capture=False)
2020-10-08 15:27:26,399 - util.py[DEBUG]: Running command ['tdnf', '-y', 'upgrade'] with allowed return codes [0] (shell=False, capture=False)
2020-10-08 15:27:26,449 - handlers.py[DEBUG]: finish: modules-final/config-package-update-upgrade-install: SUCCESS: config-package-update-upgrade-install ran successfully
2020-10-08 15:27:26,449 - stages.py[DEBUG]: Running module scripts-vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_vendor.py'>) with frequency once-per-instance
2020-10-08 15:27:26,449 - handlers.py[DEBUG]: start: modules-final/config-scripts-vendor: running config-scripts-vendor with frequency once-per-instance
2020-10-08 15:27:26,449 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_vendor - wb: [644] 23 bytes
2020-10-08 15:27:26,450 - helpers.py[DEBUG]: Running config-scripts-vendor using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_vendor'>)
2020-10-08 15:27:26,450 - handlers.py[DEBUG]: finish: modules-final/config-scripts-vendor: SUCCESS: config-scripts-vendor ran successfully
2020-10-08 15:27:26,450 - stages.py[DEBUG]: Running module scripts-per-once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once
2020-10-08 15:27:26,450 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once
2020-10-08 15:27:26,450 - helpers.py[DEBUG]: config-scripts-per-once already ran (freq=once)
2020-10-08 15:27:26,450 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once previously ran
2020-10-08 15:27:26,450 - stages.py[DEBUG]: Running module scripts-per-boot (<module 'cloudinit.config.cc_scripts_per_boot' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_boot.py'>) with frequency always
2020-10-08 15:27:26,451 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always
2020-10-08 15:27:26,451 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x7f95e1c6acd0>)
2020-10-08 15:27:26,452 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully
2020-10-08 15:27:26,452 - stages.py[DEBUG]: Running module scripts-per-instance (<module 'cloudinit.config.cc_scripts_per_instance' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_instance.py'>) with frequency once-per-instance
2020-10-08 15:27:26,452 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance
2020-10-08 15:27:26,452 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_per_instance - wb: [644] 24 bytes
2020-10-08 15:27:26,453 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_per_instance'>)
2020-10-08 15:27:26,454 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance ran successfully
2020-10-08 15:27:26,454 - stages.py[DEBUG]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance
2020-10-08 15:27:26,454 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance
2020-10-08 15:27:26,454 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_user - wb: [644] 24 bytes
2020-10-08 15:27:26,454 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_user'>)
2020-10-08 15:27:26,454 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully
2020-10-08 15:27:26,454 - stages.py[DEBUG]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequency once-per-instance
2020-10-08 15:27:26,455 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance
2020-10-08 15:27:26,455 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh_authkey_fingerprints - wb: [644] 24 bytes
2020-10-08 15:27:26,455 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh_authkey_fingerprints'>)
2020-10-08 15:27:26,456 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-10-08 15:27:26,456 - util.py[DEBUG]: Read 3265 bytes from /etc/ssh/sshd_config
2020-10-08 15:27:26,456 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False)
2020-10-08 15:27:26,456 - util.py[DEBUG]: Read 564 bytes from /root/.ssh/authorized_keys
2020-10-08 15:27:26,459 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully
2020-10-08 15:27:26,459 - stages.py[DEBUG]: Running module keys-to-console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance
2020-10-08 15:27:26,460 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance
2020-10-08 15:27:26,460 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_keys_to_console - wb: [644] 24 bytes
2020-10-08 15:27:26,460 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_keys_to_console'>)
2020-10-08 15:27:26,460 - util.py[DEBUG]: Running command ['/usr/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True)
2020-10-08 15:27:26,513 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully
2020-10-08 15:27:26,513 - stages.py[DEBUG]: Running module phone-home (<module 'cloudinit.config.cc_phone_home' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_phone_home.py'>) with frequency once-per-instance
2020-10-08 15:27:26,513 - handlers.py[DEBUG]: start: modules-final/config-phone-home: running config-phone-home with frequency once-per-instance
2020-10-08 15:27:26,513 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_phone_home - wb: [644] 21 bytes
2020-10-08 15:27:26,514 - helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_phone_home'>)
2020-10-08 15:27:26,514 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
2020-10-08 15:27:26,514 - handlers.py[DEBUG]: finish: modules-final/config-phone-home: SUCCESS: config-phone-home ran successfully
2020-10-08 15:27:26,514 - stages.py[DEBUG]: Running module final-message (<module 'cloudinit.config.cc_final_message' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_final_message.py'>) with frequency always
2020-10-08 15:27:26,514 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always
2020-10-08 15:27:26,514 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x7f95e1cc2bd0>)
2020-10-08 15:27:26,514 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-08 15:27:26,514 - util.py[DEBUG]: Read 14 bytes from /proc/uptime
2020-10-08 15:27:26,518 - util.py[DEBUG]: Cloud-init v. 19.4 finished at Thu, 08 Oct 2020 15:27:26 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net].  Up 128.57 seconds
2020-10-08 15:27:26,518 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 51 bytes
2020-10-08 15:27:26,518 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully
2020-10-08 15:27:26,519 - stages.py[DEBUG]: Running module power-state-change (<module 'cloudinit.config.cc_power_state_change' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_power_state_change.py'>) with frequency once-per-instance
2020-10-08 15:27:26,519 - handlers.py[DEBUG]: start: modules-final/config-power-state-change: running config-power-state-change with frequency once-per-instance
2020-10-08 15:27:26,519 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_power_state_change - wb: [644] 24 bytes
2020-10-08 15:27:26,519 - helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_power_state_change'>)
2020-10-08 15:27:26,519 - cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing
2020-10-08 15:27:26,519 - handlers.py[DEBUG]: finish: modules-final/config-power-state-change: SUCCESS: config-power-state-change ran successfully
2020-10-08 15:27:26,519 - main.py[DEBUG]: Ran 11 modules with 0 failures
2020-10-08 15:27:26,520 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpsihf3sal) - w: [644] 599 bytes/chars
2020-10-08 15:27:26,520 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmpsr7vvqez) - w: [644] 96 bytes/chars
2020-10-08 15:27:26,520 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
2020-10-08 15:27:26,520 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-08 15:27:26,520 - util.py[DEBUG]: Read 14 bytes from /proc/uptime
2020-10-08 15:27:26,520 - util.py[DEBUG]: cloud-init mode 'modules' took 0.464 seconds (0.46)
2020-10-08 15:27:26,520 - handlers.py[DEBUG]: finish: modules-final: SUCCESS: running modules for final
JanHolger commented 4 years ago

I've just seen that this is not the initial log, but it definitely prints the v1 network config so it is detected.

JanHolger commented 4 years ago

I've rerun to check initial log again:

2020-10-09 13:54:13,620 - util.py[DEBUG]: Cloud-init v. 19.4 running 'init-local' at Fri, 09 Oct 2020 13:54:13 +0000. Up 5.68 seconds.
2020-10-09 13:54:13,620 - main.py[DEBUG]: No kernel command line url found.
2020-10-09 13:54:13,620 - main.py[DEBUG]: Closing stdin.
2020-10-09 13:54:13,623 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-10-09 13:54:13,624 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:16
2020-10-09 13:54:13,624 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
2020-10-09 13:54:13,624 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net
2020-10-09 13:54:13,625 - handlers.py[DEBUG]: start: init-local/check-cache: attempting to read from cache [check]
2020-10-09 13:54:13,625 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-10-09 13:54:13,625 - stages.py[DEBUG]: no cache found
2020-10-09 13:54:13,625 - handlers.py[DEBUG]: finish: init-local/check-cache: SUCCESS: no cache found
2020-10-09 13:54:13,625 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-10-09 13:54:13,632 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-09 13:54:13,633 - __init__.py[DEBUG]: Looking for data source in: ['NoCloud', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2020-10-09 13:54:13,635 - __init__.py[DEBUG]: Searching for local data source in: ['DataSourceNoCloud']
2020-10-09 13:54:13,636 - handlers.py[DEBUG]: start: init-local/search-NoCloud: searching for local data from DataSourceNoCloud
2020-10-09 13:54:13,636 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceNoCloud.DataSourceNoCloud'>
2020-10-09 13:54:13,636 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: New instance first boot
2020-10-09 13:54:13,636 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:13,640 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:13,641 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:13,642 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-10-09 13:54:13,642 - util.py[DEBUG]: Read 58 bytes from /proc/1/environ
2020-10-09 13:54:13,642 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Read 1287 bytes from /proc/self/status
2020-10-09 13:54:13,643 - util.py[DEBUG]: querying dmi data /sys/class/dmi/id/product_serial
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /sys/class/dmi/id/product_serial (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Read 1 bytes from /sys/class/dmi/id/product_serial
2020-10-09 13:54:13,643 - util.py[DEBUG]: dmi data /sys/class/dmi/id/product_serial returned
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/user-data (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/meta-data (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/vendor-data (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/network-config (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/user-data (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/meta-data (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/vendor-data (quiet=False)
2020-10-09 13:54:13,643 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/network-config (quiet=False)
2020-10-09 13:54:13,646 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-10-09 13:54:13,647 - util.py[DEBUG]: Read 219 bytes from /etc/os-release
2020-10-09 13:54:13,648 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-10-09 13:54:13,657 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-10-09 13:54:13,660 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-10-09 13:54:13,669 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-10-09 13:54:13,676 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=CIDATA', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-10-09 13:54:13,681 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-10-09 13:54:13,685 - DataSourceNoCloud.py[DEBUG]: Attempting to use data from /dev/sr0
2020-10-09 13:54:13,685 - util.py[DEBUG]: Reading from /proc/mounts (quiet=False)
2020-10-09 13:54:13,686 - util.py[DEBUG]: Read 2021 bytes from /proc/mounts
2020-10-09 13:54:13,686 - util.py[DEBUG]: Fetched {'sysfs': {'fstype': 'sysfs', 'mountpoint': '/sys', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'proc': {'fstype': 'proc', 'mountpoint': '/proc', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'devtmpfs': {'fstype': 'devtmpfs', 'mountpoint': '/dev', 'opts': 'rw,nosuid,size=497428k,nr_inodes=124357,mode=755'}, 'securityfs': {'fstype': 'securityfs', 'mountpoint': '/sys/kernel/security', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'tmpfs': {'fstype': 'tmpfs', 'mountpoint': '/tmp', 'opts': 'rw,nosuid,nodev'}, 'devpts': {'fstype': 'devpts', 'mountpoint': '/dev/pts', 'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000'}, 'cgroup': {'fstype': 'cgroup', 'mountpoint': '/sys/fs/cgroup/cpuset', 'opts': 'rw,nosuid,nodev,noexec,relatime,cpuset'}, 'pstore': {'fstype': 'pstore', 'mountpoint': '/sys/fs/pstore', 'opts': 'rw,nosuid,nodev,noexec,relatime'}, 'bpf': {'fstype': 'bpf', 'mountpoint': '/sys/fs/bpf', 'opts': 'rw,nosuid,nodev,noexec,relatime,mode=700'}, '/dev/sda3': {'fstype': 'ext4', 'mountpoint': '/', 'opts': 'rw,noatime,noacl'}, 'hugetlbfs': {'fstype': 'hugetlbfs', 'mountpoint': '/dev/hugepages', 'opts': 'rw,relatime,pagesize=2M'}, 'mqueue': {'fstype': 'mqueue', 'mountpoint': '/dev/mqueue', 'opts': 'rw,relatime'}, 'debugfs': {'fstype': 'debugfs', 'mountpoint': '/sys/kernel/debug', 'opts': 'rw,relatime'}, '/dev/sda2': {'fstype': 'vfat', 'mountpoint': '/boot/efi', 'opts': 'rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,errors=remount-ro'}} mounts from proc
2020-10-09 13:54:13,686 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'auto', '/dev/sr0', '/run/cloud-init/tmp/tmpvy8hztxj'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:13,699 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpvy8hztxj//user-data (quiet=False)
2020-10-09 13:54:13,699 - util.py[DEBUG]: Read 842 bytes from /run/cloud-init/tmp/tmpvy8hztxj//user-data
2020-10-09 13:54:13,699 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpvy8hztxj//meta-data (quiet=False)
2020-10-09 13:54:13,700 - util.py[DEBUG]: Read 54 bytes from /run/cloud-init/tmp/tmpvy8hztxj//meta-data
2020-10-09 13:54:13,700 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpvy8hztxj//vendor-data (quiet=False)
2020-10-09 13:54:13,700 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpvy8hztxj//network-config (quiet=False)
2020-10-09 13:54:13,700 - util.py[DEBUG]: Read 278 bytes from /run/cloud-init/tmp/tmpvy8hztxj//network-config
2020-10-09 13:54:13,700 - util.py[DEBUG]: Running command ['umount', '/run/cloud-init/tmp/tmpvy8hztxj'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:13,713 - util.py[DEBUG]: Attempting to load yaml from string of length 54 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,714 - util.py[DEBUG]: Attempting to load yaml from string of length 278 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,717 - DataSourceNoCloud.py[DEBUG]: Using data from /dev/sr0
2020-10-09 13:54:13,717 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-10-09 13:54:13,717 - util.py[DEBUG]: Read 649 bytes from /etc/hosts
2020-10-09 13:54:13,718 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data.json (via temporary file /run/cloud-init/tmpe3rigw4u) - w: [644] 770 bytes/chars
2020-10-09 13:54:13,719 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmp8yj36m4n) - w: [600] 770 bytes/chars
2020-10-09 13:54:13,719 - handlers.py[DEBUG]: finish: init-local/search-NoCloud: SUCCESS: found local data from DataSourceNoCloud
2020-10-09 13:54:13,719 - stages.py[INFO]: Loaded datasource DataSourceNoCloud - DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-10-09 13:54:13,719 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-09 13:54:13,719 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-09 13:54:13,719 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,731 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-09 13:54:13,731 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-09 13:54:13,731 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,736 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-09 13:54:13,736 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-09 13:54:13,736 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,736 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,737 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-09 13:54:13,737 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-10-09 13:54:13,737 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8'
2020-10-09 13:54:13,739 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource (quiet=False)
2020-10-09 13:54:13,739 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource - wb: [644] 65 bytes
2020-10-09 13:54:13,739 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 65 bytes
2020-10-09 13:54:13,740 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-10-09 13:54:13,741 - util.py[DEBUG]: Read 41 bytes from /var/lib/cloud/data/instance-id
2020-10-09 13:54:13,741 - stages.py[DEBUG]: previous iid found to be 3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8
2020-10-09 13:54:13,741 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 41 bytes
2020-10-09 13:54:13,741 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 41 bytes
2020-10-09 13:54:13,742 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 41 bytes
2020-10-09 13:54:13,742 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 5514 bytes
2020-10-09 13:54:13,743 - main.py[DEBUG]: [local] init will now be targeting instance id: 3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8. new=False
2020-10-09 13:54:13,743 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-09 13:54:13,743 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-09 13:54:13,743 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,754 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-09 13:54:13,754 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-09 13:54:13,754 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,759 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-09 13:54:13,759 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-09 13:54:13,759 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,759 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:13,760 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-09 13:54:13,761 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-09 13:54:13,762 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-10-09 13:54:13,762 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-10-09 13:54:13,762 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-10-09 13:54:13,762 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2020-10-09 13:54:13,762 - __init__.py[DEBUG]: Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net] not updated for events: System boot
2020-10-09 13:54:13,763 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update on 'System boot' event
2020-10-09 13:54:13,763 - stages.py[DEBUG]: applying net config names for {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '42:e8:c2:75:78:71', 'subnets': [{'type': 'static', 'address': '10.16.33.5', 'netmask': '255.255.0.0', 'gateway': '10.16.0.1'}]}, {'type': 'nameserver', 'address': ['8.8.8.8']}]}
2020-10-09 13:54:13,763 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-10-09 13:54:13,763 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2020-10-09 13:54:13,763 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
2020-10-09 13:54:13,763 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type
2020-10-09 13:54:13,763 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
2020-10-09 13:54:13,763 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent
2020-10-09 13:54:13,763 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-10-09 13:54:13,763 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-10-09 13:54:13,763 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
2020-10-09 13:54:13,763 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False)
2020-10-09 13:54:13,764 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type
2020-10-09 13:54:13,764 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False)
2020-10-09 13:54:13,764 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent
2020-10-09 13:54:13,764 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-10-09 13:54:13,764 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2020-10-09 13:54:13,764 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-10-09 13:54:13,764 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2020-10-09 13:54:13,764 - util.py[DEBUG]: Reading from /sys/class/net/lo/operstate (quiet=False)
2020-10-09 13:54:13,764 - util.py[DEBUG]: Read 8 bytes from /sys/class/net/lo/operstate
2020-10-09 13:54:13,764 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False)
2020-10-09 13:54:13,764 - util.py[DEBUG]: Read 5 bytes from /sys/class/net/eth0/operstate
2020-10-09 13:54:13,765 - util.py[DEBUG]: Running command ['ip', '-6', 'addr', 'show', 'permanent', 'scope', 'global'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:13,779 - util.py[DEBUG]: Running command ['ip', '-4', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:13,783 - __init__.py[DEBUG]: no work necessary for renaming of [['42:e8:c2:75:78:71', 'eth0', 'virtio_net', '0x0001']]
2020-10-09 13:54:13,783 - main.py[DEBUG]: [local] Exiting. datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net] not in local mode.
2020-10-09 13:54:13,784 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpbi5a8r99) - w: [644] 518 bytes/chars
2020-10-09 13:54:13,784 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-09 13:54:13,784 - util.py[DEBUG]: Read 10 bytes from /proc/uptime
2020-10-09 13:54:13,784 - util.py[DEBUG]: cloud-init mode 'init' took 0.199 seconds (0.20)
2020-10-09 13:54:13,784 - handlers.py[DEBUG]: finish: init-local: SUCCESS: searching for local datasources
2020-10-09 13:54:26,940 - util.py[DEBUG]: Cloud-init v. 19.4 running 'init' at Fri, 09 Oct 2020 13:54:26 +0000. Up 20.00 seconds.
2020-10-09 13:54:26,940 - main.py[DEBUG]: No kernel command line url found.
2020-10-09 13:54:26,940 - main.py[DEBUG]: Closing stdin.
2020-10-09 13:54:26,944 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-10-09 13:54:26,945 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:16
2020-10-09 13:54:26,945 - util.py[DEBUG]: Running command ['ip', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:26,949 - util.py[DEBUG]: Running command ['ip', '-o', 'route', 'list'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:26,951 - util.py[DEBUG]: Running command ['ip', '--oneline', '-6', 'route', 'list', 'table', 'all'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-10-09 13:54:26,954 - main.py[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2020-10-09 13:54:26,954 - main.py[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early.
2020-10-09 13:54:26,954 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust]
2020-10-09 13:54:26,955 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-10-09 13:54:26,955 - util.py[DEBUG]: Read 5514 bytes from /var/lib/cloud/instance/obj.pkl
2020-10-09 13:54:26,958 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
2020-10-09 13:54:26,958 - util.py[DEBUG]: Read 41 bytes from /run/cloud-init/.instance-id
2020-10-09 13:54:26,958 - stages.py[DEBUG]: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-10-09 13:54:26,958 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceNoCloud [seed=/dev/sr0][dsmode=net]
2020-10-09 13:54:26,958 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-09 13:54:26,958 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-09 13:54:26,959 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,972 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-09 13:54:26,972 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-09 13:54:26,972 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,977 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-09 13:54:26,977 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-09 13:54:26,977 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,978 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,978 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-09 13:54:26,978 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-10-09 13:54:26,979 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8'
2020-10-09 13:54:26,979 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource (quiet=False)
2020-10-09 13:54:26,979 - util.py[DEBUG]: Read 65 bytes from /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource
2020-10-09 13:54:26,979 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/datasource - wb: [644] 65 bytes
2020-10-09 13:54:26,980 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 65 bytes
2020-10-09 13:54:26,980 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-10-09 13:54:26,980 - util.py[DEBUG]: Read 41 bytes from /var/lib/cloud/data/instance-id
2020-10-09 13:54:26,980 - stages.py[DEBUG]: previous iid found to be 3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8
2020-10-09 13:54:26,980 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 41 bytes
2020-10-09 13:54:26,981 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 41 bytes
2020-10-09 13:54:26,981 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 41 bytes
2020-10-09 13:54:26,982 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 5589 bytes
2020-10-09 13:54:26,982 - main.py[DEBUG]: [net] init will now be targeting instance id: 3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8. new=False
2020-10-09 13:54:26,982 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-09 13:54:26,982 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-09 13:54:26,982 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,993 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-09 13:54:26,993 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-09 13:54:26,993 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,998 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-09 13:54:26,998 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-09 13:54:26,998 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,999 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:26,999 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-09 13:54:27,000 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-10-09 13:54:27,000 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-10-09 13:54:27,000 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-10-09 13:54:27,000 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2020-10-09 13:54:27,001 - __init__.py[DEBUG]: Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net] not updated for events: System boot
2020-10-09 13:54:27,001 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update on 'System boot' event
2020-10-09 13:54:27,001 - stages.py[DEBUG]: applying net config names for {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '42:e8:c2:75:78:71', 'subnets': [{'type': 'static', 'address': '10.16.33.5', 'netmask': '255.255.0.0', 'gateway': '10.16.0.1'}]}, {'type': 'nameserver', 'address': ['8.8.8.8']}]}
2020-10-09 13:54:27,001 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-09 13:54:27,002 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-10-09 13:54:27,002 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2020-10-09 13:54:27,002 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
2020-10-09 13:54:27,002 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type
2020-10-09 13:54:27,002 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
2020-10-09 13:54:27,002 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent
2020-10-09 13:54:27,002 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-10-09 13:54:27,002 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-10-09 13:54:27,002 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
2020-10-09 13:54:27,002 - util.py[DEBUG]: Reading from /sys/class/net/eth0/addr_assign_type (quiet=False)
2020-10-09 13:54:27,002 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/eth0/addr_assign_type
2020-10-09 13:54:27,002 - util.py[DEBUG]: Reading from /sys/class/net/eth0/uevent (quiet=False)
2020-10-09 13:54:27,002 - util.py[DEBUG]: Read 25 bytes from /sys/class/net/eth0/uevent
2020-10-09 13:54:27,003 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-10-09 13:54:27,003 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/eth0/address
2020-10-09 13:54:27,003 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-10-09 13:54:27,003 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/eth0/device/device
2020-10-09 13:54:27,003 - util.py[DEBUG]: Reading from /sys/class/net/lo/operstate (quiet=False)
2020-10-09 13:54:27,003 - util.py[DEBUG]: Read 8 bytes from /sys/class/net/lo/operstate
2020-10-09 13:54:27,003 - util.py[DEBUG]: Reading from /sys/class/net/eth0/operstate (quiet=False)
2020-10-09 13:54:27,003 - util.py[DEBUG]: Read 3 bytes from /sys/class/net/eth0/operstate
2020-10-09 13:54:27,003 - util.py[DEBUG]: Running command ['ip', '-6', 'addr', 'show', 'permanent', 'scope', 'global'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,005 - util.py[DEBUG]: Running command ['ip', '-4', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,007 - __init__.py[DEBUG]: no work necessary for renaming of [['42:e8:c2:75:78:71', 'eth0', 'virtio_net', '0x0001']]
2020-10-09 13:54:27,007 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource
2020-10-09 13:54:27,007 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource
2020-10-09 13:54:27,007 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/user-data.txt - wb: [600] 842 bytes
2020-10-09 13:54:27,008 - util.py[DEBUG]: Attempting to load yaml from string of length 842 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,014 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/user-data.txt.i - wb: [600] 1147 bytes
2020-10-09 13:54:27,015 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/vendor-data.txt - wb: [600] 0 bytes
2020-10-09 13:54:27,016 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/vendor-data.txt.i - wb: [600] 308 bytes
2020-10-09 13:54:27,017 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/consume_data - wb: [644] 24 bytes
2020-10-09 13:54:27,017 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/consume_data'>)
2020-10-09 13:54:27,017 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data
2020-10-09 13:54:27,019 - stages.py[DEBUG]: Added default handler for {'text/cloud-config-jsonp', 'text/cloud-config'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2020-10-09 13:54:27,019 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
2020-10-09 13:54:27,019 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
2020-10-09 13:54:27,019 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']]
2020-10-09 13:54:27,019 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
2020-10-09 13:54:27,020 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2020-10-09 13:54:27,020 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2020-10-09 13:54:27,020 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2020-10-09 13:54:27,020 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2020-10-09 13:54:27,020 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance
2020-10-09 13:54:27,020 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Type': 'text/cloud-config', 'Content-Disposition': 'attachment; filename="part-001"'}
2020-10-09 13:54:27,020 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance
2020-10-09 13:54:27,020 - util.py[DEBUG]: Attempting to load yaml from string of length 842 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,041 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])]
2020-10-09 13:54:27,041 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2020-10-09 13:54:27,043 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/cloud-config.txt - wb: [600] 882 bytes
2020-10-09 13:54:27,044 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2020-10-09 13:54:27,044 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2020-10-09 13:54:27,044 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2020-10-09 13:54:27,044 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance
2020-10-09 13:54:27,045 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data
2020-10-09 13:54:27,045 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data
2020-10-09 13:54:27,045 - stages.py[DEBUG]: no vendordata from datasource
2020-10-09 13:54:27,045 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data
2020-10-09 13:54:27,045 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-10-09 13:54:27,045 - util.py[DEBUG]: Read 2399 bytes from /etc/cloud/cloud.cfg
2020-10-09 13:54:27,045 - util.py[DEBUG]: Attempting to load yaml from string of length 2399 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,056 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-10-09 13:54:27,056 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-10-09 13:54:27,056 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,061 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-10-09 13:54:27,061 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg
2020-10-09 13:54:27,061 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,062 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,062 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-10-09 13:54:27,063 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-10-09 13:54:27,063 - util.py[DEBUG]: Read 882 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-10-09 13:54:27,063 - util.py[DEBUG]: Attempting to load yaml from string of length 882 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,066 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-10-09 13:54:27,066 - util.py[DEBUG]: Read 882 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-10-09 13:54:27,066 - util.py[DEBUG]: Attempting to load yaml from string of length 882 with allowed root types (<class 'dict'>,)
2020-10-09 13:54:27,072 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource
2020-10-09 13:54:27,073 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 8327 bytes
2020-10-09 13:54:27,074 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource
2020-10-09 13:54:27,074 - main.py[DEBUG]: no di_report found in config.
2020-10-09 13:54:27,097 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-09 13:54:27,098 - stages.py[DEBUG]: Running module migrator (<module 'cloudinit.config.cc_migrator' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_migrator.py'>) with frequency always
2020-10-09 13:54:27,098 - handlers.py[DEBUG]: start: init-network/config-migrator: running config-migrator with frequency always
2020-10-09 13:54:27,098 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0x7f76899b96d0>)
2020-10-09 13:54:27,099 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2020-10-09 13:54:27,099 - handlers.py[DEBUG]: finish: init-network/config-migrator: SUCCESS: config-migrator ran successfully
2020-10-09 13:54:27,099 - stages.py[DEBUG]: Running module seed_random (<module 'cloudinit.config.cc_seed_random' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_seed_random.py'>) with frequency once-per-instance
2020-10-09 13:54:27,100 - handlers.py[DEBUG]: start: init-network/config-seed_random: running config-seed_random with frequency once-per-instance
2020-10-09 13:54:27,100 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_seed_random - wb: [644] 24 bytes
2020-10-09 13:54:27,100 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_seed_random'>)
2020-10-09 13:54:27,100 - cc_seed_random.py[DEBUG]: no command provided
2020-10-09 13:54:27,100 - handlers.py[DEBUG]: finish: init-network/config-seed_random: SUCCESS: config-seed_random ran successfully
2020-10-09 13:54:27,100 - stages.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_bootcmd.py'>) with frequency always
2020-10-09 13:54:27,101 - handlers.py[DEBUG]: start: init-network/config-bootcmd: running config-bootcmd with frequency always
2020-10-09 13:54:27,101 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x7f76899b92d0>)
2020-10-09 13:54:27,101 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2020-10-09 13:54:27,101 - handlers.py[DEBUG]: finish: init-network/config-bootcmd: SUCCESS: config-bootcmd ran successfully
2020-10-09 13:54:27,101 - stages.py[DEBUG]: Running module write-files (<module 'cloudinit.config.cc_write_files' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_write_files.py'>) with frequency once-per-instance
2020-10-09 13:54:27,101 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance
2020-10-09 13:54:27,101 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_write_files - wb: [644] 24 bytes
2020-10-09 13:54:27,102 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_write_files'>)
2020-10-09 13:54:27,102 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2020-10-09 13:54:27,102 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files ran successfully
2020-10-09 13:54:27,102 - stages.py[DEBUG]: Running module growpart (<module 'cloudinit.config.cc_growpart' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_growpart.py'>) with frequency always
2020-10-09 13:54:27,102 - handlers.py[DEBUG]: start: init-network/config-growpart: running config-growpart with frequency always
2020-10-09 13:54:27,102 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x7f7689a19ad0>)
2020-10-09 13:54:27,102 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg.  Using default: {'mode': 'auto', 'devices': ['/'], 'ignore_growroot_disabled': False}
2020-10-09 13:54:27,103 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,105 - cc_growpart.py[DEBUG]: growpart unable to find resizer for 'auto': No resizers available
2020-10-09 13:54:27,105 - handlers.py[DEBUG]: finish: init-network/config-growpart: SUCCESS: config-growpart ran successfully
2020-10-09 13:54:27,105 - stages.py[DEBUG]: Running module resizefs (<module 'cloudinit.config.cc_resizefs' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_resizefs.py'>) with frequency always
2020-10-09 13:54:27,105 - handlers.py[DEBUG]: start: init-network/config-resizefs: running config-resizefs with frequency always
2020-10-09 13:54:27,106 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x7f7689a19890>)
2020-10-09 13:54:27,125 - util.py[DEBUG]: Reading from /proc/433/mountinfo (quiet=False)
2020-10-09 13:54:27,125 - util.py[DEBUG]: Read 2678 bytes from /proc/433/mountinfo
2020-10-09 13:54:27,125 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/sda3 mnt_point=/ path=/
2020-10-09 13:54:27,125 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,128 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,130 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,131 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-10-09 13:54:27,131 - util.py[DEBUG]: Read 58 bytes from /proc/1/environ
2020-10-09 13:54:27,131 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-10-09 13:54:27,131 - util.py[DEBUG]: Read 1287 bytes from /proc/self/status
2020-10-09 13:54:27,131 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/sda3
2020-10-09 13:54:27,131 - util.py[DEBUG]: Running command ('resize2fs', '/dev/sda3') with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,147 - util.py[DEBUG]: Resizing took 0.015 seconds
2020-10-09 13:54:27,147 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True)
2020-10-09 13:54:27,147 - handlers.py[DEBUG]: finish: init-network/config-resizefs: SUCCESS: config-resizefs ran successfully
2020-10-09 13:54:27,147 - stages.py[DEBUG]: Running module disk_setup (<module 'cloudinit.config.cc_disk_setup' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_disk_setup.py'>) with frequency once-per-instance
2020-10-09 13:54:27,148 - handlers.py[DEBUG]: start: init-network/config-disk_setup: running config-disk_setup with frequency once-per-instance
2020-10-09 13:54:27,148 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_disk_setup - wb: [644] 24 bytes
2020-10-09 13:54:27,149 - helpers.py[DEBUG]: Running config-disk_setup using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_disk_setup'>)
2020-10-09 13:54:27,149 - handlers.py[DEBUG]: finish: init-network/config-disk_setup: SUCCESS: config-disk_setup ran successfully
2020-10-09 13:54:27,149 - stages.py[DEBUG]: Running module mounts (<module 'cloudinit.config.cc_mounts' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_mounts.py'>) with frequency once-per-instance
2020-10-09 13:54:27,149 - handlers.py[DEBUG]: start: init-network/config-mounts: running config-mounts with frequency once-per-instance
2020-10-09 13:54:27,149 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_mounts - wb: [644] 24 bytes
2020-10-09 13:54:27,150 - helpers.py[DEBUG]: Running config-mounts using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_mounts'>)
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: mounts configuration is []
2020-10-09 13:54:27,150 - util.py[DEBUG]: Reading from /etc/fstab (quiet=False)
2020-10-09 13:54:27,150 - util.py[DEBUG]: Read 257 bytes from /etc/fstab
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: changed default device ephemeral0 => None
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount ephemeral0
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: Attempting to determine the real name of swap
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: changed default device swap => None
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: Ignoring nonexistent default named mount swap
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: no need to setup swap
2020-10-09 13:54:27,150 - cc_mounts.py[DEBUG]: No modifications to fstab needed
2020-10-09 13:54:27,150 - handlers.py[DEBUG]: finish: init-network/config-mounts: SUCCESS: config-mounts ran successfully
2020-10-09 13:54:27,150 - stages.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_set_hostname.py'>) with frequency once-per-instance
2020-10-09 13:54:27,150 - handlers.py[DEBUG]: start: init-network/config-set_hostname: running config-set_hostname with frequency once-per-instance
2020-10-09 13:54:27,151 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_hostname - wb: [644] 23 bytes
2020-10-09 13:54:27,151 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_hostname'>)
2020-10-09 13:54:27,151 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-10-09 13:54:27,151 - util.py[DEBUG]: Read 649 bytes from /etc/hosts
2020-10-09 13:54:27,151 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False)
2020-10-09 13:54:27,154 - util.py[DEBUG]: Read 50 bytes from /var/lib/cloud/data/set-hostname
2020-10-09 13:54:27,154 - cc_set_hostname.py[DEBUG]: Setting the hostname to PhotonOS3 (PhotonOS3)
2020-10-09 13:54:27,155 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2020-10-09 13:54:27,155 - util.py[DEBUG]: Read 10 bytes from /etc/hostname
2020-10-09 13:54:27,155 - util.py[DEBUG]: Writing to /etc/hostname - wb: [644] 10 bytes
2020-10-09 13:54:27,155 - __init__.py[DEBUG]: Non-persistently setting the system hostname to PhotonOS3
2020-10-09 13:54:27,155 - util.py[DEBUG]: Running command ['hostname', 'PhotonOS3'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,158 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/set-hostname (via temporary file /var/lib/cloud/data/tmpkx_sgz9e) - w: [644] 51 bytes/chars
2020-10-09 13:54:27,159 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: SUCCESS: config-set_hostname ran successfully
2020-10-09 13:54:27,159 - stages.py[DEBUG]: Running module update_hostname (<module 'cloudinit.config.cc_update_hostname' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_update_hostname.py'>) with frequency always
2020-10-09 13:54:27,159 - handlers.py[DEBUG]: start: init-network/config-update_hostname: running config-update_hostname with frequency always
2020-10-09 13:54:27,159 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x7f768993af10>)
2020-10-09 13:54:27,159 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-10-09 13:54:27,159 - util.py[DEBUG]: Read 649 bytes from /etc/hosts
2020-10-09 13:54:27,160 - cc_update_hostname.py[DEBUG]: Updating hostname to PhotonOS3 (PhotonOS3)
2020-10-09 13:54:27,160 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False)
2020-10-09 13:54:27,161 - util.py[DEBUG]: Read 9 bytes from /var/lib/cloud/data/previous-hostname
2020-10-09 13:54:27,161 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2020-10-09 13:54:27,161 - util.py[DEBUG]: Read 10 bytes from /etc/hostname
2020-10-09 13:54:27,161 - __init__.py[INFO]: /var/lib/cloud/data/previous-hostname differs from /etc/hostname, assuming user maintained hostname.
2020-10-09 13:54:27,161 - handlers.py[DEBUG]: finish: init-network/config-update_hostname: SUCCESS: config-update_hostname ran successfully
2020-10-09 13:54:27,161 - stages.py[DEBUG]: Running module update_etc_hosts (<module 'cloudinit.config.cc_update_etc_hosts' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_update_etc_hosts.py'>) with frequency always
2020-10-09 13:54:27,161 - handlers.py[DEBUG]: start: init-network/config-update_etc_hosts: running config-update_etc_hosts with frequency always
2020-10-09 13:54:27,161 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x7f768993af90>)
2020-10-09 13:54:27,161 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-10-09 13:54:27,162 - util.py[DEBUG]: Read 649 bytes from /etc/hosts
2020-10-09 13:54:27,163 - util.py[DEBUG]: Reading from /etc/cloud/templates/hosts.photon.tmpl (quiet=False)
2020-10-09 13:54:27,164 - util.py[DEBUG]: Read 875 bytes from /etc/cloud/templates/hosts.photon.tmpl
2020-10-09 13:54:27,164 - templater.py[DEBUG]: Rendering content of '/etc/cloud/templates/hosts.photon.tmpl' using renderer jinja
2020-10-09 13:54:27,168 - util.py[DEBUG]: Writing to /etc/hosts - wb: [644] 649 bytes
2020-10-09 13:54:27,169 - handlers.py[DEBUG]: finish: init-network/config-update_etc_hosts: SUCCESS: config-update_etc_hosts ran successfully
2020-10-09 13:54:27,169 - stages.py[DEBUG]: Running module rsyslog (<module 'cloudinit.config.cc_rsyslog' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_rsyslog.py'>) with frequency once-per-instance
2020-10-09 13:54:27,169 - handlers.py[DEBUG]: start: init-network/config-rsyslog: running config-rsyslog with frequency once-per-instance
2020-10-09 13:54:27,170 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_rsyslog - wb: [644] 24 bytes
2020-10-09 13:54:27,170 - helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_rsyslog'>)
2020-10-09 13:54:27,170 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
2020-10-09 13:54:27,170 - handlers.py[DEBUG]: finish: init-network/config-rsyslog: SUCCESS: config-rsyslog ran successfully
2020-10-09 13:54:27,170 - stages.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_users_groups.py'>) with frequency once-per-instance
2020-10-09 13:54:27,171 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance
2020-10-09 13:54:27,171 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_users_groups - wb: [644] 24 bytes
2020-10-09 13:54:27,171 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_users_groups'>)
2020-10-09 13:54:27,172 - __init__.py[INFO]: User root already exists, skipping.
2020-10-09 13:54:27,172 - util.py[DEBUG]: Running command ['passwd', '-l', 'root'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,188 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False)
2020-10-09 13:54:27,189 - util.py[DEBUG]: Read 3218 bytes from /etc/sudoers
2020-10-09 13:54:27,191 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - ab: [None] 51 bytes
2020-10-09 13:54:27,193 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups ran successfully
2020-10-09 13:54:27,193 - stages.py[DEBUG]: Running module ssh (<module 'cloudinit.config.cc_ssh' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_ssh.py'>) with frequency once-per-instance
2020-10-09 13:54:27,193 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance
2020-10-09 13:54:27,193 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh - wb: [644] 24 bytes
2020-10-09 13:54:27,194 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh'>)
2020-10-09 13:54:27,196 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key.pub
2020-10-09 13:54:27,197 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key
2020-10-09 13:54:27,197 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key
2020-10-09 13:54:27,197 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key.pub
2020-10-09 13:54:27,197 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key.pub
2020-10-09 13:54:27,197 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key
2020-10-09 13:54:27,198 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key.pub
2020-10-09 13:54:27,198 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key
2020-10-09 13:54:27,198 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,367 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'dsa', '-N', '', '-f', '/etc/ssh/ssh_host_dsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,473 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ecdsa', '-N', '', '-f', '/etc/ssh/ssh_host_ecdsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,489 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ed25519', '-N', '', '-f', '/etc/ssh/ssh_host_ed25519_key'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:27,503 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ecdsa_key.pub (quiet=False)
2020-10-09 13:54:27,504 - util.py[DEBUG]: Read 176 bytes from /etc/ssh/ssh_host_ecdsa_key.pub
2020-10-09 13:54:27,504 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_rsa_key.pub (quiet=False)
2020-10-09 13:54:27,504 - util.py[DEBUG]: Read 396 bytes from /etc/ssh/ssh_host_rsa_key.pub
2020-10-09 13:54:27,504 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ed25519_key.pub (quiet=False)
2020-10-09 13:54:27,504 - util.py[DEBUG]: Read 96 bytes from /etc/ssh/ssh_host_ed25519_key.pub
2020-10-09 13:54:27,505 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-10-09 13:54:27,506 - util.py[DEBUG]: Read 3265 bytes from /etc/ssh/sshd_config
2020-10-09 13:54:27,507 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False)
2020-10-09 13:54:27,508 - util.py[DEBUG]: Read 564 bytes from /root/.ssh/authorized_keys
2020-10-09 13:54:27,508 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 564 bytes
2020-10-09 13:54:27,509 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2020-10-09 13:54:27,509 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-10-09 13:54:27,509 - util.py[DEBUG]: Read 3265 bytes from /etc/ssh/sshd_config
2020-10-09 13:54:27,510 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False)
2020-10-09 13:54:27,510 - util.py[DEBUG]: Read 564 bytes from /root/.ssh/authorized_keys
2020-10-09 13:54:27,510 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 564 bytes
2020-10-09 13:54:27,511 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2020-10-09 13:54:27,511 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh ran successfully
2020-10-09 13:54:27,511 - main.py[DEBUG]: Ran 14 modules with 0 failures
2020-10-09 13:54:27,511 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpvprrgnji) - w: [644] 546 bytes/chars
2020-10-09 13:54:27,511 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-09 13:54:27,512 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-10-09 13:54:27,512 - util.py[DEBUG]: cloud-init mode 'init' took 0.600 seconds (0.60)
2020-10-09 13:54:27,512 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources
2020-10-09 13:54:28,052 - util.py[DEBUG]: Cloud-init v. 19.4 running 'modules:config' at Fri, 09 Oct 2020 13:54:27 +0000. Up 21.07 seconds.
2020-10-09 13:54:28,066 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-09 13:54:28,067 - stages.py[INFO]: Skipping modules 'ssh-import-id' because they are not verified on distro 'photon'.  To run anyway, add them to 'unverified_modules' in config.
2020-10-09 13:54:28,067 - stages.py[INFO]: running unverified_modules: 'yum-add-repo, ntp'
2020-10-09 13:54:28,067 - stages.py[DEBUG]: Running module set-passwords (<module 'cloudinit.config.cc_set_passwords' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_set_passwords.py'>) with frequency once-per-instance
2020-10-09 13:54:28,068 - handlers.py[DEBUG]: start: modules-config/config-set-passwords: running config-set-passwords with frequency once-per-instance
2020-10-09 13:54:28,068 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_passwords - wb: [644] 23 bytes
2020-10-09 13:54:28,068 - helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_set_passwords'>)
2020-10-09 13:54:28,069 - cc_set_passwords.py[DEBUG]: Setting hashed password for ['root']:
2020-10-09 13:54:28,070 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-10-09 13:54:28,070 - util.py[DEBUG]: Read 219 bytes from /etc/os-release
2020-10-09 13:54:28,071 - util.py[DEBUG]: Running command ['chpasswd', '-e'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:28,092 - cc_set_passwords.py[DEBUG]: Leaving ssh config 'PasswordAuthentication' unchanged. ssh_pwauth=None
2020-10-09 13:54:28,092 - handlers.py[DEBUG]: finish: modules-config/config-set-passwords: SUCCESS: config-set-passwords ran successfully
2020-10-09 13:54:28,092 - stages.py[DEBUG]: Running module yum-add-repo (<module 'cloudinit.config.cc_yum_add_repo' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_yum_add_repo.py'>) with frequency once-per-instance
2020-10-09 13:54:28,093 - handlers.py[DEBUG]: start: modules-config/config-yum-add-repo: running config-yum-add-repo with frequency once-per-instance
2020-10-09 13:54:28,093 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_yum_add_repo - wb: [644] 24 bytes
2020-10-09 13:54:28,093 - helpers.py[DEBUG]: Running config-yum-add-repo using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_yum_add_repo'>)
2020-10-09 13:54:28,093 - cc_yum_add_repo.py[DEBUG]: Skipping module named yum-add-repo, no 'yum_repos' configuration found
2020-10-09 13:54:28,093 - handlers.py[DEBUG]: finish: modules-config/config-yum-add-repo: SUCCESS: config-yum-add-repo ran successfully
2020-10-09 13:54:28,093 - stages.py[DEBUG]: Running module ntp (<module 'cloudinit.config.cc_ntp' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_ntp.py'>) with frequency once-per-instance
2020-10-09 13:54:28,094 - handlers.py[DEBUG]: start: modules-config/config-ntp: running config-ntp with frequency once-per-instance
2020-10-09 13:54:28,094 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ntp - wb: [644] 23 bytes
2020-10-09 13:54:28,094 - helpers.py[DEBUG]: Running config-ntp using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ntp'>)
2020-10-09 13:54:28,094 - cc_ntp.py[DEBUG]: Skipping module named ntp, not present or disabled by cfg
2020-10-09 13:54:28,094 - handlers.py[DEBUG]: finish: modules-config/config-ntp: SUCCESS: config-ntp ran successfully
2020-10-09 13:54:28,094 - stages.py[DEBUG]: Running module timezone (<module 'cloudinit.config.cc_timezone' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_timezone.py'>) with frequency once-per-instance
2020-10-09 13:54:28,094 - handlers.py[DEBUG]: start: modules-config/config-timezone: running config-timezone with frequency once-per-instance
2020-10-09 13:54:28,095 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_timezone - wb: [644] 23 bytes
2020-10-09 13:54:28,095 - helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_timezone'>)
2020-10-09 13:54:28,095 - cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified
2020-10-09 13:54:28,095 - handlers.py[DEBUG]: finish: modules-config/config-timezone: SUCCESS: config-timezone ran successfully
2020-10-09 13:54:28,095 - stages.py[DEBUG]: Running module runcmd (<module 'cloudinit.config.cc_runcmd' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_runcmd.py'>) with frequency once-per-instance
2020-10-09 13:54:28,095 - handlers.py[DEBUG]: start: modules-config/config-runcmd: running config-runcmd with frequency once-per-instance
2020-10-09 13:54:28,095 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_runcmd - wb: [644] 23 bytes
2020-10-09 13:54:28,096 - helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_runcmd'>)
2020-10-09 13:54:28,096 - cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration
2020-10-09 13:54:28,096 - handlers.py[DEBUG]: finish: modules-config/config-runcmd: SUCCESS: config-runcmd ran successfully
2020-10-09 13:54:28,096 - stages.py[DEBUG]: Running module disable-ec2-metadata (<module 'cloudinit.config.cc_disable_ec2_metadata' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_disable_ec2_metadata.py'>) with frequency always
2020-10-09 13:54:28,096 - handlers.py[DEBUG]: start: modules-config/config-disable-ec2-metadata: running config-disable-ec2-metadata with frequency always
2020-10-09 13:54:28,096 - helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock (<cloudinit.helpers.DummyLock object at 0x7f8ecd822b90>)
2020-10-09 13:54:28,096 - cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled
2020-10-09 13:54:28,096 - handlers.py[DEBUG]: finish: modules-config/config-disable-ec2-metadata: SUCCESS: config-disable-ec2-metadata ran successfully
2020-10-09 13:54:28,096 - main.py[DEBUG]: Ran 6 modules with 0 failures
2020-10-09 13:54:28,097 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpnz6kpt3t) - w: [644] 574 bytes/chars
2020-10-09 13:54:28,097 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-09 13:54:28,097 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-10-09 13:54:28,097 - util.py[DEBUG]: cloud-init mode 'modules' took 0.112 seconds (0.11)
2020-10-09 13:54:28,097 - handlers.py[DEBUG]: finish: modules-config: SUCCESS: running modules for config
2020-10-09 13:54:28,606 - util.py[DEBUG]: Cloud-init v. 19.4 running 'modules:final' at Fri, 09 Oct 2020 13:54:28 +0000. Up 21.63 seconds.
2020-10-09 13:54:28,622 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.photon.Distro'>
2020-10-09 13:54:28,623 - stages.py[DEBUG]: Running module package-update-upgrade-install (<module 'cloudinit.config.cc_package_update_upgrade_install' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_package_update_upgrade_install.py'>) with frequency once-per-instance
2020-10-09 13:54:28,623 - handlers.py[DEBUG]: start: modules-final/config-package-update-upgrade-install: running config-package-update-upgrade-install with frequency once-per-instance
2020-10-09 13:54:28,623 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_package_update_upgrade_install - wb: [644] 23 bytes
2020-10-09 13:54:28,623 - helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_package_update_upgrade_install'>)
2020-10-09 13:54:28,624 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/update_sources - wb: [644] 24 bytes
2020-10-09 13:54:28,625 - helpers.py[DEBUG]: Running update-sources using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/update_sources'>)
2020-10-09 13:54:28,625 - util.py[DEBUG]: Running command ['tdnf', '-y', 'makecache'] with allowed return codes [0] (shell=False, capture=False)
2020-10-09 13:54:31,087 - util.py[DEBUG]: Running command ['tdnf', '-y', 'upgrade'] with allowed return codes [0] (shell=False, capture=False)
2020-10-09 13:54:48,657 - handlers.py[DEBUG]: finish: modules-final/config-package-update-upgrade-install: SUCCESS: config-package-update-upgrade-install ran successfully
2020-10-09 13:54:48,657 - stages.py[DEBUG]: Running module scripts-vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_vendor.py'>) with frequency once-per-instance
2020-10-09 13:54:48,658 - handlers.py[DEBUG]: start: modules-final/config-scripts-vendor: running config-scripts-vendor with frequency once-per-instance
2020-10-09 13:54:48,658 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_vendor - wb: [644] 23 bytes
2020-10-09 13:54:48,658 - helpers.py[DEBUG]: Running config-scripts-vendor using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_vendor'>)
2020-10-09 13:54:48,659 - handlers.py[DEBUG]: finish: modules-final/config-scripts-vendor: SUCCESS: config-scripts-vendor ran successfully
2020-10-09 13:54:48,659 - stages.py[DEBUG]: Running module scripts-per-once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once
2020-10-09 13:54:48,659 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once
2020-10-09 13:54:48,659 - helpers.py[DEBUG]: config-scripts-per-once already ran (freq=once)
2020-10-09 13:54:48,659 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once previously ran
2020-10-09 13:54:48,659 - stages.py[DEBUG]: Running module scripts-per-boot (<module 'cloudinit.config.cc_scripts_per_boot' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_boot.py'>) with frequency always
2020-10-09 13:54:48,659 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always
2020-10-09 13:54:48,660 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x7ff04fa05dd0>)
2020-10-09 13:54:48,661 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully
2020-10-09 13:54:48,661 - stages.py[DEBUG]: Running module scripts-per-instance (<module 'cloudinit.config.cc_scripts_per_instance' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_instance.py'>) with frequency once-per-instance
2020-10-09 13:54:48,661 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance
2020-10-09 13:54:48,661 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_per_instance - wb: [644] 24 bytes
2020-10-09 13:54:48,662 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_per_instance'>)
2020-10-09 13:54:48,663 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance ran successfully
2020-10-09 13:54:48,663 - stages.py[DEBUG]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance
2020-10-09 13:54:48,663 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance
2020-10-09 13:54:48,663 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_user - wb: [644] 24 bytes
2020-10-09 13:54:48,663 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_scripts_user'>)
2020-10-09 13:54:48,663 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully
2020-10-09 13:54:48,663 - stages.py[DEBUG]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequency once-per-instance
2020-10-09 13:54:48,664 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance
2020-10-09 13:54:48,664 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh_authkey_fingerprints - wb: [644] 24 bytes
2020-10-09 13:54:48,664 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_ssh_authkey_fingerprints'>)
2020-10-09 13:54:48,665 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-10-09 13:54:48,665 - util.py[DEBUG]: Read 3265 bytes from /etc/ssh/sshd_config
2020-10-09 13:54:48,665 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False)
2020-10-09 13:54:48,665 - util.py[DEBUG]: Read 564 bytes from /root/.ssh/authorized_keys
2020-10-09 13:54:48,668 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully
2020-10-09 13:54:48,668 - stages.py[DEBUG]: Running module keys-to-console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance
2020-10-09 13:54:48,668 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance
2020-10-09 13:54:48,668 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_keys_to_console - wb: [644] 24 bytes
2020-10-09 13:54:48,669 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_keys_to_console'>)
2020-10-09 13:54:48,669 - util.py[DEBUG]: Running command ['/usr/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True)
2020-10-09 13:54:48,724 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully
2020-10-09 13:54:48,725 - stages.py[DEBUG]: Running module phone-home (<module 'cloudinit.config.cc_phone_home' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_phone_home.py'>) with frequency once-per-instance
2020-10-09 13:54:48,725 - handlers.py[DEBUG]: start: modules-final/config-phone-home: running config-phone-home with frequency once-per-instance
2020-10-09 13:54:48,725 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_phone_home - wb: [644] 24 bytes
2020-10-09 13:54:48,726 - helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_phone_home'>)
2020-10-09 13:54:48,726 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
2020-10-09 13:54:48,726 - handlers.py[DEBUG]: finish: modules-final/config-phone-home: SUCCESS: config-phone-home ran successfully
2020-10-09 13:54:48,726 - stages.py[DEBUG]: Running module final-message (<module 'cloudinit.config.cc_final_message' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_final_message.py'>) with frequency always
2020-10-09 13:54:48,726 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always
2020-10-09 13:54:48,726 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x7ff04fa03710>)
2020-10-09 13:54:48,726 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-09 13:54:48,726 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-10-09 13:54:48,730 - util.py[DEBUG]: Cloud-init v. 19.4 finished at Fri, 09 Oct 2020 13:54:48 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=net].  Up 41.81 seconds
2020-10-09 13:54:48,730 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 50 bytes
2020-10-09 13:54:48,730 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully
2020-10-09 13:54:48,730 - stages.py[DEBUG]: Running module power-state-change (<module 'cloudinit.config.cc_power_state_change' from '/usr/lib/python3.7/site-packages/cloudinit/config/cc_power_state_change.py'>) with frequency once-per-instance
2020-10-09 13:54:48,731 - handlers.py[DEBUG]: start: modules-final/config-power-state-change: running config-power-state-change with frequency once-per-instance
2020-10-09 13:54:48,731 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_power_state_change - wb: [644] 23 bytes
2020-10-09 13:54:48,731 - helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/var/lib/cloud/instances/3cb39b23ad9d9a3256bbf9a8077f3ed469ca82d8/sem/config_power_state_change'>)
2020-10-09 13:54:48,731 - cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing
2020-10-09 13:54:48,731 - handlers.py[DEBUG]: finish: modules-final/config-power-state-change: SUCCESS: config-power-state-change ran successfully
2020-10-09 13:54:48,731 - main.py[DEBUG]: Ran 11 modules with 0 failures
2020-10-09 13:54:48,732 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpao1m9cn2) - w: [644] 602 bytes/chars
2020-10-09 13:54:48,732 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmpekqw_idx) - w: [644] 96 bytes/chars
2020-10-09 13:54:48,732 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
2020-10-09 13:54:48,732 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-10-09 13:54:48,732 - util.py[DEBUG]: Read 12 bytes from /proc/uptime
2020-10-09 13:54:48,732 - util.py[DEBUG]: cloud-init mode 'modules' took 20.192 seconds (20.19)
2020-10-09 13:54:48,732 - handlers.py[DEBUG]: finish: modules-final: SUCCESS: running modules for final
sshedi commented 4 years ago

Can you please try once by enabling VMwareGuestInfo in you cloud.cfg and let me know the results?

please use:

$ vmware-rpctool "info-set guestinfo.metadata $(cat <your yaml cfg file>)"
JanHolger commented 4 years ago

I've enabled VMwareGuestInfo, but this alone doesn't change anything. Isn't this command you asked me to try just setting the metadata statically? From the log you can see that it reads the metadata correctly, just doesn't produce a .network file, so i guess that won't change anything (tell me if i'm wrong here).

Checking "/usr/lib/python3.7/site-packages/cloudinit/distros/photon.py" the _write_network_config function expects v2 so i guess i need to patch that function to auto-detect the version and properly generate the config?

sshedi commented 4 years ago

Check /usr/lib/python3.7/site-packages/cloudinit/sources/DataSourceVMwareGuestInfo.py it also handles network configs and creates network file.

dcasota commented 4 years ago

@sshedi Is Cloud-init v. 20.3. ready to use? Spotted your updates in /specs/cloud-init.

JanHolger commented 4 years ago

@sshedi Thx, now i see why you asked me to test that out. I'll try and see if that works. Should i only put in the network-config file or concat metadata-config and network-config?

sshedi commented 4 years ago

Set metadata & network data using:

$ vmware-rpctool "info-set guestinfo.metadata $(cat <your yaml cfg file>)"
$ vmware-rpctool "info-set guestinfo.userdata $(cat <your yaml cfg file>)"

And proceed with your things.

@dcasota - you can try cloud-init 20.3, it's in dev branch, if you find any issue please feel free to report it.

JanHolger commented 4 years ago

Tried that but ends up in an error https://prnt.sc/uw7z3z. It's not running inside VMware so i guess executing an rpc on VMware won't work. Should i just update the _write_network_config in the distro to work with both versions and do a pull request?

sshedi commented 4 years ago

Feel free to send a PR, I'm not sure about the procedure for github PRs. @suezzelur - need your inputs here.

dcasota commented 4 years ago

@sshedi No I cannot try it myself at least not for the near future. I saw the "Cloud-init v. 19.4" in the logfile of @JanHolger.

sshedi commented 4 years ago

Tried that but ends up in an error https://prnt.sc/uw7z3z. It's not running inside VMware so i guess executing an rpc on VMware won't work. Should i just update the _write_network_config in the distro to work with both versions and do a pull request?

If you haven't installed open-vm-tools, install it using tdnf install -y open-vm-tools and then try. You can check whether a package is installed using rpm -q <package-name>

JanHolger commented 4 years ago

open-vm-tools is installed and the command exists as you can see in the screenshot, but it obviously can't send anything to VMware unless i'm running it in VMware

JanHolger commented 4 years ago

Ok the function _write_network_config in the distro class is not even executed by cloud-init, even though the distro is set to photon in cloud.cfg so my patch is useless aswell.

dcasota commented 4 years ago

@JanHolger In reference to cloudinit.readthedocs.io you could for testing purposes inject the network settings in the network-interfaces field of metadata. One of your logfile shows /dev/sr0 and /dev/sr1. Which one in the logfiles is the seed.iso? The seed.iso mounted holds the files user-data and meta-data. cloud-init parses four possible files user-data, meta-data, vendor-data and network-config what I've learned so far. If your data is not processed, the default value is set from vendor-data (photon). There are not explicit errors in the logfile, but there are plenty of messages like this one "loaded blob returned None, returning default.".

In cloudinit.readthedocs.io there's a note "Version 1 is legacy and should be considered deprecated". In Proxmox ' citype there is a note about nocloud and configdrive support. Nocloud is recommended, but, the arguments against configdrive clearly are referring to matching interfaces by name issues. Proxmox and Photon both support configdrive. Stumbled through the proxmox forum, the users&developers there use configdrive in distros as well.

A PR, backporting a patch to nocloud (version 1), is an option. To contribute to the coding as well. In addition, if the seed.iso is processed in any case automatically, and not using meta-data for network settings, it should be possible to use the configdrive support. The config below is assembled from the theory learnings. Nevertheless, I hope this helps.

network:
    ethernets:
        id0:
            addresses:
            - w.x.y.z/255.255.255.128
            dhcp4: false
            dhcp6: false
            gateway4: w.x.y.z
            match:
                macaddress: nn:nn:nn:nn:nn:n
            nameservers:
                addresses:
                - w.x.y.z
            set-name: eth0
    version: 2
JanHolger commented 4 years ago

Tried configdrive2 now which uses ENI style network config and for this reason doesn't work either https://prnt.sc/uwhgd0. Unfortunately ProxMox only supports these 2 types and generating the seed.iso manually is no viable option. ProxMox is trash in this aspect and switching to VMware or OpenStack might be a good idea but isn't an option for us now.

I tried modifying the photon distro class to support v1 but this isn't even called so i guess the problem is even deeper in cloud-init so writing an own cloud-init implementation would probably be easier than trying to find the origin of the problem.

At this point the only options i see is either writing some dirty scripts as cloud-init (from what i've seen) has a scripts folder with different event subdirectories or giving up and going back to a fat debian system which isn't great for just running kubernetes nodes on.

I really thank you for all your tips and help. If i find a solution i'll share it here but for now i'll close the issue.