Created
December 19, 2019 21:56
-
-
Save igalic/6cfa360eb13d2c2396f6a4cea63c912d to your computer and use it in GitHub Desktop.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
2019-12-19 20:57:56,122 - util.py[DEBUG]: Cloud-init v. 19.4 running 'init-local' at Thu, 19 Dec 2019 20:57:56 +0000. Up 1576789076.0785627 seconds. | |
2019-12-19 20:57:56,123 - main.py[DEBUG]: No kernel command line url found. | |
2019-12-19 20:57:56,123 - main.py[DEBUG]: Closing stdin. | |
2019-12-19 20:57:56,127 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes | |
2019-12-19 20:57:56,129 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0 | |
2019-12-19 20:57:56,130 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished | |
2019-12-19 20:57:56,130 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net | |
2019-12-19 20:57:56,130 - handlers.py[DEBUG]: start: init-local/check-cache: attempting to read from cache [check] | |
2019-12-19 20:57:56,131 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False) | |
2019-12-19 20:57:56,131 - stages.py[DEBUG]: no cache found | |
2019-12-19 20:57:56,131 - handlers.py[DEBUG]: finish: init-local/check-cache: SUCCESS: no cache found | |
2019-12-19 20:57:56,131 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance | |
2019-12-19 20:57:56,133 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'> | |
2019-12-19 20:57:56,134 - __init__.py[DEBUG]: Looking for data source in: ['Hetzner', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM'] | |
2019-12-19 20:57:56,139 - __init__.py[DEBUG]: Searching for local data source in: ['DataSourceHetzner'] | |
2019-12-19 20:57:56,139 - handlers.py[DEBUG]: start: init-local/search-Hetzner: searching for local data from DataSourceHetzner | |
2019-12-19 20:57:56,139 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceHetzner.DataSourceHetzner'> | |
2019-12-19 20:57:56,140 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: New instance first boot | |
2019-12-19 20:57:56,140 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,160 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,185 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,205 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False) | |
2019-12-19 20:57:56,206 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False) | |
2019-12-19 20:57:56,206 - util.py[DEBUG]: querying dmi data /sys/class/dmi/id/sys_vendor | |
2019-12-19 20:57:56,206 - util.py[DEBUG]: did not find /sys/class/dmi/id/sys_vendor | |
2019-12-19 20:57:56,206 - util.py[DEBUG]: Running command ['/usr/local/sbin/dmidecode', '--string', 'system-manufacturer'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,228 - util.py[DEBUG]: dmidecode returned 'Hetzner' for 'system-manufacturer' | |
2019-12-19 20:57:56,257 - util.py[DEBUG]: Running command ['uname', '-r'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,278 - util.py[DEBUG]: Running command ['ifconfig', '-l', '-u', 'ether'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,302 - url_helper.py[DEBUG]: [0/1] open 'http://169.254.169.254/hetzner/v1/metadata' with {'url': 'http://169.254.169.254/hetzner/v1/metadata', 'allow_redirects': True, 'method': 'GET', 'timeout': 5.0, 'headers': {'User-Agent': 'Cloud-Init/19.4'}} configuration | |
2019-12-19 20:57:56,309 - url_helper.py[DEBUG]: Read from http://169.254.169.254/hetzner/v1/metadata (200, 6152b) after 1 attempts | |
2019-12-19 20:57:56,309 - __init__.py[DEBUG]: Skip ephemeral network setup, instance has connectivity to http://169.254.169.254/hetzner/v1/metadata | |
2019-12-19 20:57:56,309 - url_helper.py[DEBUG]: [0/61] open 'http://169.254.169.254/hetzner/v1/metadata' with {'url': 'http://169.254.169.254/hetzner/v1/metadata', 'allow_redirects': True, 'method': 'GET', 'timeout': 2.0, 'headers': {'User-Agent': 'Cloud-Init/19.4'}} configuration | |
2019-12-19 20:57:56,312 - url_helper.py[DEBUG]: Read from http://169.254.169.254/hetzner/v1/metadata (200, 6152b) after 1 attempts | |
2019-12-19 20:57:56,312 - util.py[DEBUG]: Attempting to load yaml from string of length 6152 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,325 - url_helper.py[DEBUG]: [0/61] open 'http://169.254.169.254/hetzner/v1/userdata' with {'url': 'http://169.254.169.254/hetzner/v1/userdata', 'allow_redirects': True, 'method': 'GET', 'timeout': 2.0, 'headers': {'User-Agent': 'Cloud-Init/19.4'}} configuration | |
2019-12-19 20:57:56,328 - url_helper.py[DEBUG]: Read from http://169.254.169.254/hetzner/v1/userdata (200, 655b) after 1 attempts | |
2019-12-19 20:57:56,328 - handlers.py[DEBUG]: finish: init-local/search-Hetzner: SUCCESS: found local data from DataSourceHetzner | |
2019-12-19 20:57:56,328 - stages.py[INFO]: Loaded datasource DataSourceHetzner - DataSourceHetzner | |
2019-12-19 20:57:56,329 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False) | |
2019-12-19 20:57:56,329 - util.py[DEBUG]: Read 2016 bytes from /usr/local/etc/cloud/cloud.cfg | |
2019-12-19 20:57:56,329 - util.py[DEBUG]: Attempting to load yaml from string of length 2016 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,338 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) | |
2019-12-19 20:57:56,340 - util.py[DEBUG]: Read 2057 bytes from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg | |
2019-12-19 20:57:56,340 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,354 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) | |
2019-12-19 20:57:56,354 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg | |
2019-12-19 20:57:56,354 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,355 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,356 - util.py[DEBUG]: loaded blob returned None, returning default. | |
2019-12-19 20:57:56,357 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance | |
2019-12-19 20:57:56,357 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/3857485' | |
2019-12-19 20:57:56,360 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/3857485/datasource (quiet=False) | |
2019-12-19 20:57:56,360 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/datasource - wb: [644] 37 bytes | |
2019-12-19 20:57:56,361 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 37 bytes | |
2019-12-19 20:57:56,362 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False) | |
2019-12-19 20:57:56,362 - stages.py[DEBUG]: previous iid found to be NO_PREVIOUS_INSTANCE_ID | |
2019-12-19 20:57:56,362 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 8 bytes | |
2019-12-19 20:57:56,362 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 8 bytes | |
2019-12-19 20:57:56,363 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 24 bytes | |
2019-12-19 20:57:56,364 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 10504 bytes | |
2019-12-19 20:57:56,365 - main.py[DEBUG]: [local] init will now be targeting instance id: 3857485. new=True | |
2019-12-19 20:57:56,365 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False) | |
2019-12-19 20:57:56,365 - util.py[DEBUG]: Read 2016 bytes from /usr/local/etc/cloud/cloud.cfg | |
2019-12-19 20:57:56,365 - util.py[DEBUG]: Attempting to load yaml from string of length 2016 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,375 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) | |
2019-12-19 20:57:56,375 - util.py[DEBUG]: Read 2057 bytes from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg | |
2019-12-19 20:57:56,375 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,380 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) | |
2019-12-19 20:57:56,380 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg | |
2019-12-19 20:57:56,380 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,381 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:56,381 - util.py[DEBUG]: loaded blob returned None, returning default. | |
2019-12-19 20:57:56,382 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'> | |
2019-12-19 20:57:56,383 - cc_set_hostname.py[DEBUG]: Setting the hostname to ubuntu-2gb-fsn1-1 (ubuntu-2gb-fsn1-1) | |
2019-12-19 20:57:56,383 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False) | |
2019-12-19 20:57:56,383 - util.py[DEBUG]: Read 301 bytes from /etc/rc.conf | |
2019-12-19 20:57:56,384 - util.py[DEBUG]: Writing to /etc/rc.conf - wb: [644] 301 bytes | |
2019-12-19 20:57:56,384 - __init__.py[DEBUG]: Non-persistently setting the system hostname to ubuntu-2gb-fsn1-1 | |
2019-12-19 20:57:56,384 - util.py[DEBUG]: Running command ['hostname', 'ubuntu-2gb-fsn1-1'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,405 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/set-hostname (via temporary file /var/lib/cloud/data/tmphg1injva) - w: [644] 67 bytes/chars | |
2019-12-19 20:57:56,406 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False) | |
2019-12-19 20:57:56,407 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,428 - __init__.py[DEBUG]: net: all expected physical devices present | |
2019-12-19 20:57:56,428 - stages.py[DEBUG]: applying net config names for {'config': [{'mac_address': '96:00:00:3a:01:94', 'name': 'eth0', 'subnets': [{'dns_nameservers': ['213.133.100.100', '213.133.98.98', '213.133.99.99'], 'ipv4': True, 'type': 'dhcp'}, {'address': '2a01:4f8:c17:b08::1/64', 'gateway': 'fe80::1', 'ipv6': True, 'type': 'static'}], 'type': 'physical'}], 'version': 1} | |
2019-12-19 20:57:56,428 - stages.py[INFO]: Applying network configuration from ds bringup=False: {'config': [{'mac_address': '96:00:00:3a:01:94', 'name': 'eth0', 'subnets': [{'dns_nameservers': ['213.133.100.100', '213.133.98.98', '213.133.99.99'], 'ipv4': True, 'type': 'dhcp'}, {'address': '2a01:4f8:c17:b08::1/64', 'gateway': 'fe80::1', 'ipv6': True, 'type': 'static'}], 'type': 'physical'}], 'version': 1} | |
2019-12-19 20:57:56,429 - __init__.py[DEBUG]: Selected renderer 'freebsd' from priority list: None | |
2019-12-19 20:57:56,433 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:56,454 - freebsd.py[INFO]: Configuring interface eth0 | |
2019-12-19 20:57:56,455 - freebsd.py[DEBUG]: Configuring dev eth0 with 2a01:4f8:c17:b08::1 / None | |
2019-12-19 20:57:56,455 - util.py[WARNING]: failed stage init-local | |
2019-12-19 20:57:56,455 - util.py[DEBUG]: failed stage init-local | |
Traceback (most recent call last): | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/cmd/main.py", line 653, in status_wrapper | |
ret = functor(name, args) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/cmd/main.py", line 362, in main_init | |
init.apply_network_config(bring_up=bool(mode != sources.DSMODE_LOCAL)) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/stages.py", line 710, in apply_network_config | |
return self.distro.apply_network_config(netcfg, bring_up=bring_up) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/distros/__init__.py", line 178, in apply_network_config | |
dev_names = self._write_network_config(netconfig) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/distros/freebsd.py", line 197, in _write_network_config | |
return self._supported_write_network_config(netconfig) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/distros/__init__.py", line 93, in _supported_write_network_config | |
renderer.render_network_config(network_config) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/net/renderer.py", line 56, in render_network_config | |
templates=templates, target=target) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/net/freebsd.py", line 145, in render_network_state | |
self._write_network(network_state, target=target) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/net/freebsd.py", line 138, in _write_network | |
self._write_ifconfig_entries(settings, target=target) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/net/freebsd.py", line 59, in _write_ifconfig_entries | |
subnet.get('netmask')) | |
TypeError: must be str, not NoneType | |
2019-12-19 20:57:56,467 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpu7f8vjq3) - w: [644] 510 bytes/chars | |
2019-12-19 20:57:56,468 - util.py[DEBUG]: cloud-init mode 'init' took 0.457 seconds (0.46) | |
2019-12-19 20:57:56,469 - handlers.py[DEBUG]: finish: init-local: SUCCESS: searching for local datasources | |
2019-12-19 20:57:57,955 - util.py[DEBUG]: Cloud-init v. 19.4 running 'init' at Thu, 19 Dec 2019 20:57:57 +0000. Up 1576789077.91531 seconds. | |
2019-12-19 20:57:57,955 - main.py[DEBUG]: No kernel command line url found. | |
2019-12-19 20:57:57,955 - main.py[DEBUG]: Closing stdin. | |
2019-12-19 20:57:57,957 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes | |
2019-12-19 20:57:57,958 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0 | |
2019-12-19 20:57:57,958 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0, 1] (shell=False, capture=True) | |
2019-12-19 20:57:57,984 - util.py[DEBUG]: Running command ['netstat', '--route', '--numeric', '--extend'] with allowed return codes [0, 1] (shell=False, capture=True) | |
2019-12-19 20:57:58,016 - util.py[DEBUG]: Running command ['netstat', '-A', 'inet6', '--route', '--numeric'] with allowed return codes [0, 1] (shell=False, capture=True) | |
2019-12-19 20:57:58,041 - main.py[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early. | |
2019-12-19 20:57:58,041 - main.py[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early. | |
2019-12-19 20:57:58,042 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust] | |
2019-12-19 20:57:58,042 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False) | |
2019-12-19 20:57:58,042 - util.py[DEBUG]: Read 10504 bytes from /var/lib/cloud/instance/obj.pkl | |
2019-12-19 20:57:58,044 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False) | |
2019-12-19 20:57:58,044 - util.py[DEBUG]: Read 8 bytes from /run/cloud-init/.instance-id | |
2019-12-19 20:57:58,044 - stages.py[DEBUG]: restored from cache with run check: DataSourceHetzner | |
2019-12-19 20:57:58,045 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceHetzner | |
2019-12-19 20:57:58,045 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False) | |
2019-12-19 20:57:58,045 - util.py[DEBUG]: Read 2016 bytes from /usr/local/etc/cloud/cloud.cfg | |
2019-12-19 20:57:58,045 - util.py[DEBUG]: Attempting to load yaml from string of length 2016 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,054 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) | |
2019-12-19 20:57:58,054 - util.py[DEBUG]: Read 2057 bytes from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg | |
2019-12-19 20:57:58,054 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,060 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) | |
2019-12-19 20:57:58,060 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg | |
2019-12-19 20:57:58,060 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,061 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,061 - util.py[DEBUG]: loaded blob returned None, returning default. | |
2019-12-19 20:57:58,061 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance | |
2019-12-19 20:57:58,062 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/3857485' | |
2019-12-19 20:57:58,063 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/3857485/datasource (quiet=False) | |
2019-12-19 20:57:58,063 - util.py[DEBUG]: Read 37 bytes from /var/lib/cloud/instances/3857485/datasource | |
2019-12-19 20:57:58,063 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/datasource - wb: [644] 37 bytes | |
2019-12-19 20:57:58,063 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 37 bytes | |
2019-12-19 20:57:58,064 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False) | |
2019-12-19 20:57:58,064 - util.py[DEBUG]: Read 8 bytes from /var/lib/cloud/data/instance-id | |
2019-12-19 20:57:58,064 - stages.py[DEBUG]: previous iid found to be 3857485 | |
2019-12-19 20:57:58,064 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 8 bytes | |
2019-12-19 20:57:58,065 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 8 bytes | |
2019-12-19 20:57:58,065 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 8 bytes | |
2019-12-19 20:57:58,066 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 10592 bytes | |
2019-12-19 20:57:58,067 - main.py[DEBUG]: [net] init will now be targeting instance id: 3857485. new=False | |
2019-12-19 20:57:58,067 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False) | |
2019-12-19 20:57:58,067 - util.py[DEBUG]: Read 2016 bytes from /usr/local/etc/cloud/cloud.cfg | |
2019-12-19 20:57:58,067 - util.py[DEBUG]: Attempting to load yaml from string of length 2016 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,076 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) | |
2019-12-19 20:57:58,076 - util.py[DEBUG]: Read 2057 bytes from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg | |
2019-12-19 20:57:58,076 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,085 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) | |
2019-12-19 20:57:58,085 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg | |
2019-12-19 20:57:58,085 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,086 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,086 - util.py[DEBUG]: loaded blob returned None, returning default. | |
2019-12-19 20:57:58,088 - __init__.py[DEBUG]: Datasource DataSourceHetzner not updated for events: System boot | |
2019-12-19 20:57:58,088 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update on 'System boot' event | |
2019-12-19 20:57:58,088 - stages.py[DEBUG]: applying net config names for {'config': [{'mac_address': '96:00:00:3a:01:94', 'name': 'eth0', 'subnets': [{'dns_nameservers': ['213.133.100.100', '213.133.98.98', '213.133.99.99'], 'ipv4': True, 'type': 'dhcp'}, {'address': '2a01:4f8:c17:b08::1/64', 'gateway': 'fe80::1', 'ipv6': True, 'type': 'static'}], 'type': 'physical'}], 'version': 1} | |
2019-12-19 20:57:58,088 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'> | |
2019-12-19 20:57:58,089 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource | |
2019-12-19 20:57:58,089 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource | |
2019-12-19 20:57:58,089 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/user-data.txt - wb: [600] 655 bytes | |
2019-12-19 20:57:58,091 - util.py[DEBUG]: Attempting to load yaml from string of length 655 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,096 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/user-data.txt.i - wb: [600] 960 bytes | |
2019-12-19 20:57:58,097 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/vendor-data.txt - wb: [600] 5025 bytes | |
2019-12-19 20:57:58,099 - util.py[DEBUG]: Attempting to load yaml from string of length 4304 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,109 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/vendor-data.txt.i - wb: [600] 4996 bytes | |
2019-12-19 20:57:58,110 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False) | |
2019-12-19 20:57:58,110 - util.py[DEBUG]: Read 67 bytes from /var/lib/cloud/data/set-hostname | |
2019-12-19 20:57:58,110 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set-hostname | |
2019-12-19 20:57:58,111 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/consume_data - wb: [644] 26 bytes | |
2019-12-19 20:57:58,111 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/consume_data'>) | |
2019-12-19 20:57:58,112 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data | |
2019-12-19 20:57:58,112 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] | |
2019-12-19 20:57:58,112 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']] | |
2019-12-19 20:57:58,112 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']] | |
2019-12-19 20:57:58,113 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']] | |
2019-12-19 20:57:58,113 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']] | |
2019-12-19 20:57:58,113 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,113 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,113 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,113 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,113 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,113 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Type': 'text/cloud-config', 'Content-Disposition': 'attachment; filename="part-001"'} | |
2019-12-19 20:57:58,113 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, part-001, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,114 - util.py[DEBUG]: Attempting to load yaml from string of length 655 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,117 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])] | |
2019-12-19 20:57:58,117 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,120 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/cloud-config.txt - wb: [600] 543 bytes | |
2019-12-19 20:57:58,121 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,121 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,121 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,121 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,121 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data | |
2019-12-19 20:57:58,121 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data | |
2019-12-19 20:57:58,121 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) | |
2019-12-19 20:57:58,122 - util.py[DEBUG]: Read 543 bytes from /var/lib/cloud/instance/cloud-config.txt | |
2019-12-19 20:57:58,122 - util.py[DEBUG]: Attempting to load yaml from string of length 543 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,125 - stages.py[DEBUG]: vendor data will be consumed. disabled_handlers=None | |
2019-12-19 20:57:58,126 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] | |
2019-12-19 20:57:58,126 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']] | |
2019-12-19 20:57:58,126 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']] | |
2019-12-19 20:57:58,126 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']] | |
2019-12-19 20:57:58,126 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']] | |
2019-12-19 20:57:58,126 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,126 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,126 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,127 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,127 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,127 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Transfer-Encoding': '7bit', 'Content-Disposition': 'attachment; filename="cloud-config"', 'Content-Type': 'text/cloud-config'} | |
2019-12-19 20:57:58,127 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (text/cloud-config, cloud-config, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,127 - util.py[DEBUG]: Attempting to load yaml from string of length 4304 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,136 - cloud_config.py[DEBUG]: Merging by applying [('dict', ['replace']), ('list', []), ('str', [])] | |
2019-12-19 20:57:58,137 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Transfer-Encoding': '7bit', 'Content-Disposition': 'attachment; filename="hc-boot-script"', 'Content-Type': 'text/x-shellscript'} | |
2019-12-19 20:57:58,137 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (text/x-shellscript, hc-boot-script, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,137 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/scripts/vendor/hc-boot-script - wb: [700] 168 bytes | |
2019-12-19 20:57:58,138 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,146 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/vendor-cloud-config.txt - wb: [600] 4562 bytes | |
2019-12-19 20:57:58,147 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,147 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,147 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance | |
2019-12-19 20:57:58,147 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance | |
2019-12-19 20:57:58,147 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data | |
2019-12-19 20:57:58,148 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False) | |
2019-12-19 20:57:58,148 - util.py[DEBUG]: Read 2016 bytes from /usr/local/etc/cloud/cloud.cfg | |
2019-12-19 20:57:58,148 - util.py[DEBUG]: Attempting to load yaml from string of length 2016 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,158 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False) | |
2019-12-19 20:57:58,158 - util.py[DEBUG]: Read 2057 bytes from /usr/local/etc/cloud/cloud.cfg.d/05_logging.cfg | |
2019-12-19 20:57:58,158 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,164 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False) | |
2019-12-19 20:57:58,164 - util.py[DEBUG]: Read 35 bytes from /run/cloud-init/cloud.cfg | |
2019-12-19 20:57:58,164 - util.py[DEBUG]: Attempting to load yaml from string of length 35 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,165 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,165 - util.py[DEBUG]: loaded blob returned None, returning default. | |
2019-12-19 20:57:58,166 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) | |
2019-12-19 20:57:58,166 - util.py[DEBUG]: Read 543 bytes from /var/lib/cloud/instance/cloud-config.txt | |
2019-12-19 20:57:58,166 - util.py[DEBUG]: Attempting to load yaml from string of length 543 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,170 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/vendor-cloud-config.txt (quiet=False) | |
2019-12-19 20:57:58,170 - util.py[DEBUG]: Read 4562 bytes from /var/lib/cloud/instance/vendor-cloud-config.txt | |
2019-12-19 20:57:58,170 - util.py[DEBUG]: Attempting to load yaml from string of length 4562 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,182 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False) | |
2019-12-19 20:57:58,183 - util.py[DEBUG]: Read 543 bytes from /var/lib/cloud/instance/cloud-config.txt | |
2019-12-19 20:57:58,183 - util.py[DEBUG]: Attempting to load yaml from string of length 543 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,186 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/vendor-cloud-config.txt (quiet=False) | |
2019-12-19 20:57:58,186 - util.py[DEBUG]: Read 4562 bytes from /var/lib/cloud/instance/vendor-cloud-config.txt | |
2019-12-19 20:57:58,186 - util.py[DEBUG]: Attempting to load yaml from string of length 4562 with allowed root types (<class 'dict'>,) | |
2019-12-19 20:57:58,198 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource | |
2019-12-19 20:57:58,199 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 17969 bytes | |
2019-12-19 20:57:58,200 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource | |
2019-12-19 20:57:58,200 - main.py[DEBUG]: no di_report found in config. | |
2019-12-19 20:57:58,224 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'> | |
2019-12-19 20:57:58,226 - stages.py[DEBUG]: Running module migrator (<module 'cloudinit.config.cc_migrator' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_migrator.py'>) with frequency always | |
2019-12-19 20:57:58,227 - handlers.py[DEBUG]: start: init-network/config-migrator: running config-migrator with frequency always | |
2019-12-19 20:57:58,227 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0x8034aaba8>) | |
2019-12-19 20:57:58,228 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names | |
2019-12-19 20:57:58,229 - handlers.py[DEBUG]: finish: init-network/config-migrator: SUCCESS: config-migrator ran successfully | |
2019-12-19 20:57:58,229 - stages.py[DEBUG]: Running module seed_random (<module 'cloudinit.config.cc_seed_random' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_seed_random.py'>) with frequency once-per-instance | |
2019-12-19 20:57:58,230 - handlers.py[DEBUG]: start: init-network/config-seed_random: running config-seed_random with frequency once-per-instance | |
2019-12-19 20:57:58,231 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_seed_random - wb: [644] 26 bytes | |
2019-12-19 20:57:58,233 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_seed_random'>) | |
2019-12-19 20:57:58,233 - cc_seed_random.py[DEBUG]: seed_random: adding 2048 bytes of random seed entropy to /dev/urandom | |
2019-12-19 20:57:58,233 - util.py[DEBUG]: Writing to /dev/urandom - ab: [None] 2048 bytes | |
2019-12-19 20:57:58,336 - cc_seed_random.py[DEBUG]: no command provided | |
2019-12-19 20:57:58,336 - handlers.py[DEBUG]: finish: init-network/config-seed_random: SUCCESS: config-seed_random ran successfully | |
2019-12-19 20:57:58,336 - stages.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_bootcmd.py'>) with frequency always | |
2019-12-19 20:57:58,337 - handlers.py[DEBUG]: start: init-network/config-bootcmd: running config-bootcmd with frequency always | |
2019-12-19 20:57:58,337 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x8034f9978>) | |
2019-12-19 20:57:58,337 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration | |
2019-12-19 20:57:58,337 - handlers.py[DEBUG]: finish: init-network/config-bootcmd: SUCCESS: config-bootcmd ran successfully | |
2019-12-19 20:57:58,338 - stages.py[DEBUG]: Running module write-files (<module 'cloudinit.config.cc_write_files' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_write_files.py'>) with frequency once-per-instance | |
2019-12-19 20:57:58,338 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance | |
2019-12-19 20:57:58,339 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_write_files - wb: [644] 26 bytes | |
2019-12-19 20:57:58,340 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_write_files'>) | |
2019-12-19 20:57:58,340 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration | |
2019-12-19 20:57:58,340 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files ran successfully | |
2019-12-19 20:57:58,340 - stages.py[DEBUG]: Running module growpart (<module 'cloudinit.config.cc_growpart' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_growpart.py'>) with frequency always | |
2019-12-19 20:57:58,341 - handlers.py[DEBUG]: start: init-network/config-growpart: running config-growpart with frequency always | |
2019-12-19 20:57:58,341 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x803500240>) | |
2019-12-19 20:57:58,341 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg. Using default: {'mode': 'auto', 'devices': ['/'], 'ignore_growroot_disabled': False} | |
2019-12-19 20:57:58,341 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,366 - util.py[DEBUG]: Running command ['mount'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,393 - util.py[DEBUG]: found line in mount -> devpth: zroot/ROOT/default, mount_point: /, fs_type: zfs | |
2019-12-19 20:57:58,420 - util.py[DEBUG]: Running command ['uname', '-r'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,445 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,470 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,495 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,519 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False) | |
2019-12-19 20:57:58,520 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False) | |
2019-12-19 20:57:58,520 - util.py[DEBUG]: resize_devices took 0.154 seconds | |
2019-12-19 20:57:58,520 - cc_growpart.py[DEBUG]: '/' SKIPPED: stat of 'zroot/ROOT/default' failed: [Errno 2] No such file or directory: 'zroot/ROOT/default' | |
2019-12-19 20:57:58,520 - handlers.py[DEBUG]: finish: init-network/config-growpart: SUCCESS: config-growpart ran successfully | |
2019-12-19 20:57:58,521 - stages.py[DEBUG]: Running module resizefs (<module 'cloudinit.config.cc_resizefs' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_resizefs.py'>) with frequency always | |
2019-12-19 20:57:58,521 - handlers.py[DEBUG]: start: init-network/config-resizefs: running config-resizefs with frequency always | |
2019-12-19 20:57:58,521 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x803579f28>) | |
2019-12-19 20:57:58,627 - util.py[DEBUG]: Running command ['mount'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,653 - util.py[DEBUG]: found line in mount -> devpth: zroot/ROOT/default, mount_point: /, fs_type: zfs | |
2019-12-19 20:57:58,654 - util.py[DEBUG]: Running command ['zpool', 'status', 'zroot'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,684 - util.py[DEBUG]: found zpool "zroot" on disk da0p3 | |
2019-12-19 20:57:58,684 - cc_resizefs.py[DEBUG]: resize_info: dev=da0p3 mnt_point=/ path=zroot | |
2019-12-19 20:57:58,685 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,709 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,733 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,753 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False) | |
2019-12-19 20:57:58,753 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False) | |
2019-12-19 20:57:58,753 - cc_resizefs.py[DEBUG]: 'da0p3' doesn't appear to be a valid device path. Trying '/dev/da0p3' | |
2019-12-19 20:57:58,754 - cc_resizefs.py[DEBUG]: Resizing zroot (zfs) using zpool online -e zroot /dev/da0p3 | |
2019-12-19 20:57:58,754 - util.py[DEBUG]: Running command ('zpool', 'online', '-e', 'zroot', '/dev/da0p3') with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,867 - util.py[DEBUG]: Resizing took 0.113 seconds | |
2019-12-19 20:57:58,868 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=zfs, val=True) | |
2019-12-19 20:57:58,868 - handlers.py[DEBUG]: finish: init-network/config-resizefs: SUCCESS: config-resizefs ran successfully | |
2019-12-19 20:57:58,868 - stages.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_set_hostname.py'>) with frequency once-per-instance | |
2019-12-19 20:57:58,869 - handlers.py[DEBUG]: start: init-network/config-set_hostname: running config-set_hostname with frequency once-per-instance | |
2019-12-19 20:57:58,870 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_set_hostname - wb: [644] 26 bytes | |
2019-12-19 20:57:58,871 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_set_hostname'>) | |
2019-12-19 20:57:58,871 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False) | |
2019-12-19 20:57:58,871 - util.py[DEBUG]: Read 67 bytes from /var/lib/cloud/data/set-hostname | |
2019-12-19 20:57:58,871 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set-hostname | |
2019-12-19 20:57:58,872 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: SUCCESS: config-set_hostname ran successfully | |
2019-12-19 20:57:58,872 - stages.py[DEBUG]: Running module update_hostname (<module 'cloudinit.config.cc_update_hostname' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_update_hostname.py'>) with frequency always | |
2019-12-19 20:57:58,872 - handlers.py[DEBUG]: start: init-network/config-update_hostname: running config-update_hostname with frequency always | |
2019-12-19 20:57:58,872 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x8036129b0>) | |
2019-12-19 20:57:58,872 - cc_update_hostname.py[DEBUG]: Updating hostname to ubuntu-2gb-fsn1-1 (ubuntu-2gb-fsn1-1) | |
2019-12-19 20:57:58,873 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False) | |
2019-12-19 20:57:58,873 - util.py[DEBUG]: Read 301 bytes from /etc/rc.conf | |
2019-12-19 20:57:58,873 - __init__.py[DEBUG]: Attempting to update hostname to ubuntu-2gb-fsn1-1 in 1 files | |
2019-12-19 20:57:58,874 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False) | |
2019-12-19 20:57:58,874 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-hostname - wb: [644] 94 bytes | |
2019-12-19 20:57:58,876 - handlers.py[DEBUG]: finish: init-network/config-update_hostname: SUCCESS: config-update_hostname ran successfully | |
2019-12-19 20:57:58,876 - stages.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_users_groups.py'>) with frequency once-per-instance | |
2019-12-19 20:57:58,877 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance | |
2019-12-19 20:57:58,877 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_users_groups - wb: [644] 25 bytes | |
2019-12-19 20:57:58,878 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_users_groups'>) | |
2019-12-19 20:57:58,879 - freebsd.py[INFO]: User root already exists, skipping. | |
2019-12-19 20:57:58,879 - util.py[DEBUG]: Running command ['pw', 'usermod', 'root', '-h', '-'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 20:57:58,906 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False) | |
2019-12-19 20:57:58,907 - util.py[DEBUG]: Read 260 bytes from /etc/sudoers | |
2019-12-19 20:57:58,908 - util.py[DEBUG]: Writing to /usr/local/etc/sudoers.d/90-cloud-init-users - ab: [None] 51 bytes | |
2019-12-19 20:57:58,910 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups ran successfully | |
2019-12-19 20:57:58,910 - stages.py[DEBUG]: Running module ssh (<module 'cloudinit.config.cc_ssh' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_ssh.py'>) with frequency once-per-instance | |
2019-12-19 20:57:58,911 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance | |
2019-12-19 20:57:58,911 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_ssh - wb: [644] 25 bytes | |
2019-12-19 20:57:58,912 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_ssh'>) | |
2019-12-19 20:57:58,913 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key | |
2019-12-19 20:57:58,913 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key | |
2019-12-19 20:57:58,913 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key.pub | |
2019-12-19 20:57:58,914 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key.pub | |
2019-12-19 20:57:58,914 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_dsa_key.pub | |
2019-12-19 20:57:58,914 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key | |
2019-12-19 20:57:58,914 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key | |
2019-12-19 20:57:58,914 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key.pub | |
2019-12-19 20:57:58,915 - 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) | |
2019-12-19 20:57:58,976 - 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) | |
2019-12-19 20:57:59,103 - 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) | |
2019-12-19 20:57:59,128 - 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) | |
2019-12-19 20:57:59,155 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ed25519_key.pub (quiet=False) | |
2019-12-19 20:57:59,156 - util.py[DEBUG]: Read 104 bytes from /etc/ssh/ssh_host_ed25519_key.pub | |
2019-12-19 20:57:59,156 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ecdsa_key.pub (quiet=False) | |
2019-12-19 20:57:59,156 - util.py[DEBUG]: Read 184 bytes from /etc/ssh/ssh_host_ecdsa_key.pub | |
2019-12-19 20:57:59,156 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_rsa_key.pub (quiet=False) | |
2019-12-19 20:57:59,156 - util.py[DEBUG]: Read 404 bytes from /etc/ssh/ssh_host_rsa_key.pub | |
2019-12-19 20:57:59,158 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False) | |
2019-12-19 20:57:59,158 - util.py[DEBUG]: Read 3344 bytes from /etc/ssh/sshd_config | |
2019-12-19 20:57:59,158 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False) | |
2019-12-19 20:57:59,158 - util.py[DEBUG]: Read 81 bytes from /root/.ssh/authorized_keys | |
2019-12-19 20:57:59,159 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 81 bytes | |
2019-12-19 20:57:59,160 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0 | |
2019-12-19 20:57:59,160 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False) | |
2019-12-19 20:57:59,160 - util.py[DEBUG]: Read 3344 bytes from /etc/ssh/sshd_config | |
2019-12-19 20:57:59,161 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False) | |
2019-12-19 20:57:59,161 - util.py[DEBUG]: Read 81 bytes from /root/.ssh/authorized_keys | |
2019-12-19 20:57:59,161 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 81 bytes | |
2019-12-19 20:57:59,162 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0 | |
2019-12-19 20:57:59,162 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh ran successfully | |
2019-12-19 20:57:59,162 - main.py[DEBUG]: Ran 10 modules with 0 failures | |
2019-12-19 20:57:59,163 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp7wwvi6wl) - w: [644] 552 bytes/chars | |
2019-12-19 20:57:59,164 - util.py[DEBUG]: cloud-init mode 'init' took 1.312 seconds (1.31) | |
2019-12-19 20:57:59,164 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources | |
2019-12-19 20:58:00,489 - util.py[DEBUG]: Cloud-init v. 19.4 running 'modules:final' at Thu, 19 Dec 2019 20:58:00 +0000. Up 1576789080.2623858 seconds. | |
2019-12-19 20:58:00,503 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'> | |
2019-12-19 20:58:00,504 - stages.py[DEBUG]: Running module package-update-upgrade-install (<module 'cloudinit.config.cc_package_update_upgrade_install' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_package_update_upgrade_install.py'>) with frequency once-per-instance | |
2019-12-19 20:58:00,505 - handlers.py[DEBUG]: start: modules-final/config-package-update-upgrade-install: running config-package-update-upgrade-install with frequency once-per-instance | |
2019-12-19 20:58:00,505 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_package_update_upgrade_install - wb: [644] 26 bytes | |
2019-12-19 20:58:00,506 - helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_package_update_upgrade_install'>) | |
2019-12-19 20:58:00,506 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/update_sources - wb: [644] 26 bytes | |
2019-12-19 20:58:00,507 - helpers.py[DEBUG]: Running update-sources using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/update_sources'>) | |
2019-12-19 20:58:00,507 - util.py[DEBUG]: Running command ['pkg', 'update'] with allowed return codes [0] (shell=False, capture=False) | |
2019-12-19 21:00:54,810 - helpers.py[DEBUG]: update-sources already ran (freq=once-per-instance) | |
2019-12-19 21:00:54,811 - util.py[DEBUG]: Running command ['pkg', 'install', 'python36', 'tmux', 'neovim', 'git', 'tig', 'ripgrep', 'rubygem-pry', 'rubygem-r10k'] with allowed return codes [0] (shell=False, capture=False) | |
2019-12-19 21:00:55,581 - handlers.py[DEBUG]: finish: modules-final/config-package-update-upgrade-install: SUCCESS: config-package-update-upgrade-install ran successfully | |
2019-12-19 21:00:55,582 - stages.py[DEBUG]: Running module salt-minion (<module 'cloudinit.config.cc_salt_minion' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_salt_minion.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,583 - handlers.py[DEBUG]: start: modules-final/config-salt-minion: running config-salt-minion with frequency once-per-instance | |
2019-12-19 21:00:55,584 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_salt_minion - wb: [644] 26 bytes | |
2019-12-19 21:00:55,585 - helpers.py[DEBUG]: Running config-salt-minion using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_salt_minion'>) | |
2019-12-19 21:00:55,586 - cc_salt_minion.py[DEBUG]: Skipping module named salt-minion, no 'salt_minion' key in configuration | |
2019-12-19 21:00:55,586 - handlers.py[DEBUG]: finish: modules-final/config-salt-minion: SUCCESS: config-salt-minion ran successfully | |
2019-12-19 21:00:55,586 - stages.py[DEBUG]: Running module rightscale_userdata (<module 'cloudinit.config.cc_rightscale_userdata' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_rightscale_userdata.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,587 - handlers.py[DEBUG]: start: modules-final/config-rightscale_userdata: running config-rightscale_userdata with frequency once-per-instance | |
2019-12-19 21:00:55,587 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_rightscale_userdata - wb: [644] 26 bytes | |
2019-12-19 21:00:55,588 - helpers.py[DEBUG]: Running config-rightscale_userdata using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_rightscale_userdata'>) | |
2019-12-19 21:00:55,588 - cc_rightscale_userdata.py[DEBUG]: Failed to get raw userdata in module rightscale_userdata | |
2019-12-19 21:00:55,589 - handlers.py[DEBUG]: finish: modules-final/config-rightscale_userdata: SUCCESS: config-rightscale_userdata ran successfully | |
2019-12-19 21:00:55,589 - stages.py[DEBUG]: Running module scripts-vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_vendor.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,589 - handlers.py[DEBUG]: start: modules-final/config-scripts-vendor: running config-scripts-vendor with frequency once-per-instance | |
2019-12-19 21:00:55,590 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_scripts_vendor - wb: [644] 26 bytes | |
2019-12-19 21:00:55,591 - helpers.py[DEBUG]: Running config-scripts-vendor using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_scripts_vendor'>) | |
2019-12-19 21:00:55,592 - util.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts/vendor/hc-boot-script'] with allowed return codes [0] (shell=False, capture=False) | |
2019-12-19 21:00:55,615 - util.py[WARNING]: Failed running /var/lib/cloud/instance/scripts/vendor/hc-boot-script [-] | |
2019-12-19 21:00:55,616 - util.py[DEBUG]: Failed running /var/lib/cloud/instance/scripts/vendor/hc-boot-script [-] | |
Traceback (most recent call last): | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/util.py", line 2048, in subp | |
env=env, shell=shell) | |
File "/usr/local/lib/python3.6/subprocess.py", line 729, in __init__ | |
restore_signals, start_new_session) | |
File "/usr/local/lib/python3.6/subprocess.py", line 1364, in _execute_child | |
raise child_exception_type(errno_num, err_msg, err_filename) | |
FileNotFoundError: [Errno 2] No such file or directory: b'/var/lib/cloud/instance/scripts/vendor/hc-boot-script': b'/var/lib/cloud/instance/scripts/vendor/hc-boot-script' | |
During handling of the above exception, another exception occurred: | |
Traceback (most recent call last): | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/util.py", line 896, in runparts | |
subp(prefix + [exe_path], capture=False) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/util.py", line 2056, in subp | |
stderr="-" if decode else b"-") | |
cloudinit.util.ProcessExecutionError: Unexpected error while running command. | |
Command: ['/var/lib/cloud/instance/scripts/vendor/hc-boot-script'] | |
Exit code: - | |
Reason: [Errno 2] No such file or directory: b'/var/lib/cloud/instance/scripts/vendor/hc-boot-script': b'/var/lib/cloud/instance/scripts/vendor/hc-boot-script' | |
Stdout: - | |
Stderr: - | |
2019-12-19 21:00:55,619 - cc_scripts_vendor.py[WARNING]: Failed to run module scripts-vendor (vendor in /var/lib/cloud/instance/scripts/vendor) | |
2019-12-19 21:00:55,620 - handlers.py[DEBUG]: finish: modules-final/config-scripts-vendor: FAIL: running config-scripts-vendor with frequency once-per-instance | |
2019-12-19 21:00:55,620 - util.py[WARNING]: Running module scripts-vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_vendor.py'>) failed | |
2019-12-19 21:00:55,620 - util.py[DEBUG]: Running module scripts-vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_vendor.py'>) failed | |
Traceback (most recent call last): | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/stages.py", line 851, in _run_modules | |
freq=freq) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/cloud.py", line 54, in run | |
return self._runners.run(name, functor, args, freq, clear_on_fail) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/helpers.py", line 187, in run | |
results = functor(*args) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_vendor.py", line 49, in handle | |
util.runparts(runparts_path, exe_prefix=prefix) | |
File "/usr/local/lib/python3.6/site-packages/cloudinit/util.py", line 903, in runparts | |
% (len(failed), len(attempted))) | |
RuntimeError: Runparts: 1 failures in 1 attempted commands | |
2019-12-19 21:00:55,623 - stages.py[DEBUG]: Running module scripts-per-once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once | |
2019-12-19 21:00:55,623 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once | |
2019-12-19 21:00:55,624 - util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [644] 26 bytes | |
2019-12-19 21:00:55,624 - helpers.py[DEBUG]: Running config-scripts-per-once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>) | |
2019-12-19 21:00:55,625 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once ran successfully | |
2019-12-19 21:00:55,625 - stages.py[DEBUG]: Running module scripts-per-boot (<module 'cloudinit.config.cc_scripts_per_boot' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_per_boot.py'>) with frequency always | |
2019-12-19 21:00:55,625 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always | |
2019-12-19 21:00:55,625 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x8034d1828>) | |
2019-12-19 21:00:55,626 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully | |
2019-12-19 21:00:55,626 - stages.py[DEBUG]: Running module scripts-per-instance (<module 'cloudinit.config.cc_scripts_per_instance' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_per_instance.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,626 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance | |
2019-12-19 21:00:55,626 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_scripts_per_instance - wb: [644] 26 bytes | |
2019-12-19 21:00:55,627 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_scripts_per_instance'>) | |
2019-12-19 21:00:55,627 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance ran successfully | |
2019-12-19 21:00:55,627 - stages.py[DEBUG]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,627 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance | |
2019-12-19 21:00:55,628 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_scripts_user - wb: [644] 26 bytes | |
2019-12-19 21:00:55,628 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_scripts_user'>) | |
2019-12-19 21:00:55,628 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully | |
2019-12-19 21:00:55,629 - stages.py[DEBUG]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,629 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance | |
2019-12-19 21:00:55,629 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_ssh_authkey_fingerprints - wb: [644] 25 bytes | |
2019-12-19 21:00:55,630 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_ssh_authkey_fingerprints'>) | |
2019-12-19 21:00:55,630 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False) | |
2019-12-19 21:00:55,631 - util.py[DEBUG]: Read 3344 bytes from /etc/ssh/sshd_config | |
2019-12-19 21:00:55,631 - util.py[DEBUG]: Reading from /root/.ssh/authorized_keys (quiet=False) | |
2019-12-19 21:00:55,631 - util.py[DEBUG]: Read 81 bytes from /root/.ssh/authorized_keys | |
2019-12-19 21:00:55,632 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully | |
2019-12-19 21:00:55,632 - stages.py[DEBUG]: Running module keys-to-console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,632 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance | |
2019-12-19 21:00:55,632 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_keys_to_console - wb: [644] 26 bytes | |
2019-12-19 21:00:55,633 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_keys_to_console'>) | |
2019-12-19 21:00:55,634 - util.py[DEBUG]: Running command ['/usr/local/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True) | |
2019-12-19 21:00:55,688 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully | |
2019-12-19 21:00:55,689 - stages.py[DEBUG]: Running module phone-home (<module 'cloudinit.config.cc_phone_home' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_phone_home.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,689 - handlers.py[DEBUG]: start: modules-final/config-phone-home: running config-phone-home with frequency once-per-instance | |
2019-12-19 21:00:55,689 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_phone_home - wb: [644] 26 bytes | |
2019-12-19 21:00:55,690 - helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_phone_home'>) | |
2019-12-19 21:00:55,691 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found | |
2019-12-19 21:00:55,691 - handlers.py[DEBUG]: finish: modules-final/config-phone-home: SUCCESS: config-phone-home ran successfully | |
2019-12-19 21:00:55,691 - stages.py[DEBUG]: Running module final-message (<module 'cloudinit.config.cc_final_message' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_final_message.py'>) with frequency always | |
2019-12-19 21:00:55,691 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always | |
2019-12-19 21:00:55,691 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x8034d5860>) | |
2019-12-19 21:00:55,699 - util.py[DEBUG]: Cloud-init v. 19.4 finished at Thu, 19 Dec 2019 21:00:55 +0000. Datasource DataSourceHetzner. Up 1576789255.6922395 seconds | |
2019-12-19 21:00:55,699 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 63 bytes | |
2019-12-19 21:00:55,700 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully | |
2019-12-19 21:00:55,700 - stages.py[DEBUG]: Running module power-state-change (<module 'cloudinit.config.cc_power_state_change' from '/usr/local/lib/python3.6/site-packages/cloudinit/config/cc_power_state_change.py'>) with frequency once-per-instance | |
2019-12-19 21:00:55,700 - handlers.py[DEBUG]: start: modules-final/config-power-state-change: running config-power-state-change with frequency once-per-instance | |
2019-12-19 21:00:55,701 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/3857485/sem/config_power_state_change - wb: [644] 25 bytes | |
2019-12-19 21:00:55,701 - helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/var/lib/cloud/instances/3857485/sem/config_power_state_change'>) | |
2019-12-19 21:00:55,701 - cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing | |
2019-12-19 21:00:55,702 - handlers.py[DEBUG]: finish: modules-final/config-power-state-change: SUCCESS: config-power-state-change ran successfully | |
2019-12-19 21:00:55,702 - main.py[DEBUG]: Ran 13 modules with 1 failures | |
2019-12-19 21:00:55,702 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp_34grpfp) - w: [644] 671 bytes/chars | |
2019-12-19 21:00:55,703 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmplsmdrzsd) - w: [644] 190 bytes/chars | |
2019-12-19 21:00:55,703 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json' | |
2019-12-19 21:00:55,704 - util.py[DEBUG]: cloud-init mode 'modules' took 175.445 seconds (175.45) | |
2019-12-19 21:00:55,704 - handlers.py[DEBUG]: finish: modules-final: FAIL: running modules for final |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment