Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add update_etc_hosts as default module on *BSD #479

Merged
merged 4 commits into from
Jul 7, 2020
Merged

Add update_etc_hosts as default module on *BSD #479

merged 4 commits into from
Jul 7, 2020

Conversation

ad-m
Copy link
Contributor

@ad-m ad-m commented Jul 5, 2020

If I understand correctly, Cloud-init adopts the default configuration to run all supported modules on a given distro. For unknown reasons, the update_etc_hosts module does not run on FreeBSD and NetBSD, although:

  • module update_etc_hosts has sense and retains functionality,
  • module update_etc_hosts is working on the platform, in accordance with its documentation and manual tests.

In our environment, we assume that all images should have /etc/hosts file managed by default. FreeBSD is an exception due default Cloud-init config.

According Git history @goneri provided recently support for NetBSD and follow that configuration, so I ask him for review.

This distinction has been made to this configuration file in a change 41d46bf but that patch follow earlier configuration file
https://github.com/canonical/cloud-init/blob/e7c95208451422cfd3da7edfbd67dd271e7aa337/config/cloud.cfg-freebsd which turned it off in the patch c36d755. However, assumptions behind disable this module no longer seem valid.

Copy link
Collaborator

@igalic igalic left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

last time i looked over this, #385 i only focused on configuration management, and didn't look closer at other modules

could you also provide us with the log of a boot like in that pr?

@ad-m
Copy link
Contributor Author

ad-m commented Jul 5, 2020

Here is boot log (h1 vm serialport log of FreeBSD on RbxCloud) with update_etc_hosts module enabled:

Copyright (c) 1992-2019 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
	The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 12.1-RELEASE r354233 GENERIC amd64
FreeBSD clang version 8.0.1 (tags/RELEASE_801/final 366581) (based on LLVM 8.0.1)
SRAT: Ignoring memory at addr 0x80200000
SRAT: Ignoring memory at addr 0x100000000
SRAT: Ignoring memory at addr 0x1000000000
VT(vga): text 80x25
Hyper-V Version: 10.0.14393 [SP3]
  Features=0xe7f<VPRUNTIME,TMREFCNT,SYNIC,SYNTM,APIC,HYPERCALL,VPINDEX,REFTSC,IDLE,TMFREQ>
  PM Features=0x0 [C2]
  Features3=0x7b2<DEBUG,XMMHC,IDLE,NUMA,TMFREQ,SYNCMC,CRASH>
Timecounter "Hyper-V" frequency 10000000 Hz quality 2000
CPU: Intel(R) Xeon(R) CPU E5-2673 v3 @ 2.40GHz (2400.00-MHz K8-class CPU)
  Origin="GenuineIntel"  Id=0x306f2  Family=0x6  Model=0x3f  Stepping=2
  Features=0xf83fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE,SSE2,SS>
  Features2=0x80002001<SSE3,CX16,HV>
  AMD Features=0x20100800<SYSCALL,NX,LM>
  AMD Features2=0x1<LAHF>
  Structured Extended Features3=0x94000000<IBPB,L1DFL,SSBD>
Hypervisor: Origin = "Microsoft Hv"
real memory  = 2147483648 (2048 MB)
avail memory = 2043269120 (1948 MB)
Event timer "LAPIC" quality 100
ACPI APIC Table: <VRTUAL MICROSFT>
arc4random: no preloaded entropy cache
ioapic0: Changing APIC ID to 0
ioapic0 <Version 1.1> irqs 0-23 on motherboard
Timecounter "TSC-low" frequency 1200001478 Hz quality 800
Timecounter "Hyper-V-TSC" frequency 10000000 Hz quality 3000
random: entropy device external interface
kbd1 at kbdmux0
000.000023 [4335] netmap_init               netmap: loaded module
[ath_hal] loaded
module_register_init: MOD_LOAD (vesa, 0xffffffff8112e050, 0) error 19
nexus0
vtvga0: <VT VGA driver> on motherboard
cryptosoft0: <software crypto> on motherboard
acpi0: <VRTUAL MICROSFT> on motherboard
acpi0: Power Button (fixed)
cpu0: <ACPI CPU> on acpi0
attimer0: <AT timer> port 0x40-0x43 irq 0 on acpi0
Timecounter "i8254" frequency 1193182 Hz quality 0
Event timer "i8254" frequency 1193182 Hz quality 100
atrtc0: <AT realtime clock> port 0x70-0x71 irq 8 on acpi0
atrtc0: registered as a time-of-day clock, resolution 1.000000s
Event timer "RTC" frequency 32768 Hz quality 0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
acpi_timer0: <32-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pcib0: Length mismatch for 3 range: 20000000 vs 1fffffff
vmbus0: <Hyper-V Vmbus> on pcib0
pci0: <ACPI PCI bus> on pcib0
isab0: <PCI-ISA bridge> at device 7.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel PIIX4 UDMA33 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xffa0-0xffaf at device 7.1 on pci0
ata0: <ATA channel> at channel 0 on atapci0
ata1: <ATA channel> at channel 1 on atapci0
pci0: <bridge> at device 7.3 (no driver attached)
vgapci0: <VGA-compatible display> mem 0xf8000000-0xfbffffff irq 11 at device 8.0 on pci0
vgapci0: Boot video device
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model IntelliMouse Explorer, device ID 4
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
uart0: console (9600,n,8,1)
uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
fdc0: <floppy drive controller (FDE)> port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
vmbus_res0: <Hyper-V Vmbus Resource> irq 5,7 on acpi0
orm0: <ISA Option ROM> at iomem 0xc0000-0xcbfff pnpid ORM0000 on isa0
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff pnpid PNP0900 on isa0
Timecounters tick every 10.000 msec
usb_needs_explore_all: no devclass
vmbus0: version 3.0
hvet0: <Hyper-V event timer> on vmbus0
Event timer "Hyper-V" frequency 10000000 Hz quality 1000
storvsc0: <Hyper-V IDE> on vmbus0
hvkbd0: <Hyper-V KBD> on vmbus0
hvheartbeat0: <Hyper-V Heartbeat> on vmbus0
hvshutdown0: <Hyper-V Shutdown> on vmbus0
hvtimesync0: <Hyper-V Timesync> on vmbus0
hvtimesync0: RTT
hvvss0: <Hyper-V VSS> on vmbus0
storvsc1: <Hyper-V SCSI> on vmbus0
hn0: <Hyper-V Network Interface> on vmbus0
hn0: Ethernet address: 00:15:5d:ff:62:ee
hn0: link state changed to UP
cd0 at ata1 bus 0 scbus1 target 0 lun 0
cd0: <Msft Virtual CD/ROM 1.0> Removable CD-ROM SPC-3 SCSI device
cd0: 16.700MB/s transfers (WDMA2, ATAPI 12bytes, PIO 65534bytes)
cd0: Attempt to query device size failed: NOT READY, Medium not present
da0 at blkvsc0 bus 0 scbus2 target 0 lun 0
da0: <Msft Virtual Disk 1.0> Fixed Direct Access SPC-3 SCSI device
da0: 300.000MB/s transfers
da0: Command Queueing enabled
da0: 25600MB (52428800 512 byte sectors)
Trying to mount root from ufs:/dev/gpt/root [rw,noatime]...
Setting hostuuid: 53596ac2-be6d-6548-b01f-dc73ddd83087.
Setting hostid: 0x794dff67.
Starting file system checks:
/dev/gpt/root: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/gpt/root: clean, 5978109 free (709 frags, 747175 blocks, 0.0% fragmentation)
Mounting local filesystems:.
ELF ldconfig path: /lib /usr/lib /usr/lib/compat /usr/local/lib
random: unblocking device.
32-bit compatibility ldconfig path: /usr/lib32
/usr/local/bin/cloud-init startingWARN: no logging configured! (tried 0 configs)
Setting up basic logging...
Cloud-init v. 20.1 running 'init-local' at Sun, 05 Jul 2020 15:28:21 +0000. Up 8.549607276916504 seconds.
2020-07-05 15:28:21,494 - util.py[DEBUG]: Cloud-init v. 20.1 running 'init-local' at Sun, 05 Jul 2020 15:28:21 +0000. Up 8.549607276916504 seconds.
2020-07-05 15:28:21,547 - main.py[DEBUG]: No kernel command line url found.
2020-07-05 15:28:21,574 - main.py[DEBUG]: Closing stdin.
2020-07-05 15:28:21,647 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-07-05 15:28:21,691 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2020-07-05 15:28:21,727 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
2020-07-05 15:28:21,763 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net
2020-07-05 15:28:21,796 - handlers.py[DEBUG]: start: init-local/check-cache: attempting to read from cache [check]
2020-07-05 15:28:21,839 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-07-05 15:28:21,882 - stages.py[DEBUG]: no cache found
2020-07-05 15:28:21,902 - handlers.py[DEBUG]: finish: init-local/check-cache: SUCCESS: no cache found
2020-07-05 15:28:21,938 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-07-05 15:28:21,971 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'>
2020-07-05 15:28:22,012 - __init__.py[DEBUG]: Looking for data source in: ['RbxCloud'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2020-07-05 15:28:22,094 - __init__.py[DEBUG]: Searching for local data source in: ['DataSourceRbxCloud']
2020-07-05 15:28:22,137 - handlers.py[DEBUG]: start: init-local/search-RbxCloud: searching for local data from DataSourceRbxCloud
2020-07-05 15:28:22,240 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceRbxCloud.DataSourceRbxCloud'>
2020-07-05 15:28:22,303 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: New instance first boot
2020-07-05 15:28:22,391 - util.py[DEBUG]: Running command ['uname', '-r'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:22,458 - util.py[DEBUG]: Running command mount with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:22,512 - util.py[DEBUG]: Fetched {'/dev/gpt/root': {'fstype': 'ufs', 'mountpoint': '/', 'opts': 'noatime'}} mounts from mount
2020-07-05 15:28:22,586 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'vfat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpt372qlaa'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:22,705 - util.py[DEBUG]: Failed mount of '/dev/msdosfs/CLOUDMD' as 'vfat': Unexpected error while running command.
Command: ['mount', '-o', 'ro', '-t', 'vfat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpt372qlaa']
Exit code: 1
Reason: -
Stdout: 
Stderr: mount: /dev/msdosfs/CLOUDMD: Operation not supported by device
2020-07-05 15:28:22,825 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'fat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpt372qlaa'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:22,936 - util.py[DEBUG]: Failed mount of '/dev/msdosfs/CLOUDMD' as 'fat': Unexpected error while running command.
Command: ['mount', '-o', 'ro', '-t', 'fat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpt372qlaa']
Exit code: 1
Reason: -
Stdout: 
Stderr: mount: /dev/msdosfs/CLOUDMD: Operation not supported by device
2020-07-05 15:28:23,055 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'msdosfs', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpt372qlaa'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:23,163 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpt372qlaa/cloud.json (quiet=False)
2020-07-05 15:28:23,239 - util.py[DEBUG]: Read 1900 bytes from /run/cloud-init/tmp/tmpt372qlaa/cloud.json
2020-07-05 15:28:23,282 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpt372qlaa/user.data (quiet=True)
2020-07-05 15:28:23,332 - util.py[DEBUG]: Read 0 bytes from /run/cloud-init/tmp/tmpt372qlaa/user.data
2020-07-05 15:28:23,372 - util.py[DEBUG]: Reading from /etc/hosts (quiet=True)
2020-07-05 15:2:23,403 - util.py[DEBUG]: Read 0 bytes from /etc/hosts
2020-07-05 15:28:23,408 - DataSourceRbxCloud.py[DEBUG]: /etc/hosts does not exists - setting manage_etc_hosts to True
2020-07-05 15:28:23,408 - DataSourceRbxCloud.py[DEBUG]: returning DATA object:
2020-07-05 15:28:23,408 - DataSourceRbxCloud.py[DEBUG]: {'userdata': '', 'metadata': {'instance-id': '5f01f12f8073de470f52eba3', 'local-hostname': 'my-freebsd', 'public-keys': []}, 'gratuitous_arp': [{'source': '62.181.8.231', 'destination': '62.181.8.1'}, {'source': '62.181.8.231', 'destination': '62.181.8.3'}, {'source': '62.181.8.231', 'destination': '62.181.8.4'}], 'cfg': {'ssh_pwauth': True, 'disable_root': True, 'system_info': {'default_user': {'name': 'guru', 'gecos': 'guru', 'sudo': ['ALL=(ALL) NOPASSWD:ALL'], 'passwd': '....', 'lock_passwd': False, 'ssh_authorized_keys': ['ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC4XemXNeaQINC9oxgWlhTfkhIngyUahYGHKuDrmV9PUbOvTrO5suUqe9aIOK873uYJVsQ33wkKi73GlF0Ht5FMM+3DbRl3zULnA0PaOOj728KbaCx/ijikGcMC2K3NTBXO1k/f3TDcQiSF92n4Pce6CwNCyeJP0zHecj/5WFsDEvKD1TBpBW0DsJWZ32oTvrZ57/0sH1zo9nxf1KXK9g+fzV2ef31W6X1hQrygKjtQKYSPw4/Nx2R3nuYtDePi3jyM5nRwvXiTeoTb0HNBZ9H8UXvPdBoexxvDqtIJV7S/MpwYh2ptC/UtJYsfI3f6e5tc1xtJAjKWHjc9TolVl9Fb adas@adas-Latitude-E7450', 'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDWBN979NdMeISmieALgwcr6aKJlhIpbTcP35XHotnC35HBK9VluOKNEVAuCBgY9R96qzsRtSXocug21cnqHgyqKlf9qN5YnjnzDRKZxZ+JQngvJ+vzp3HX/rxjMSdQh0vErz4WhFYwAbk51QetvAUD/Pgjw8sbO2kmCMbEovw/6ereYKOZ6NPK96YoLaCLuFnQpw8dbxCjAK/T/V3iVy5ByP4cAsUTXkOxpmHlcy0EskUMgeu4oapMiLKbAmVd3pg+4dHPs/rbvZFv3D0OrRiRxClp2XbuV4M7VzGFVB1M1wdZVCL9di40ZWdByDLCmbIr+JEt7sp4MYeuo3M88zxl adas@adas-Latitude-E7450', 'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDyiqfRnHMBNxOEvO7FAeup7c6EUiFX+rGdtXunE9N6FcHA8swHt90Ip6euRNR1S4h0dIY8Qy9s/orH4+Vh8OizscfY1Looo5w6qiJ1JGSJroEduw4g8I1w7w57sctgPU8XA9U3TQX+f5S8/9wowRehGlQUx6GQJkh+Q1uFsqJ2j8Mju4Ef7wK4KN6i3VGkYqVRbGrIJHUQZrALpJGq2n4Q9mLG6zCopsMqNdkZr1uxI2DkA/TWPIwfiWjsmZjBY2X13O3i+JVDQtsVJu1PqCezCrmiOIC4UgEhHIurZiDyYdcpZVxncThmPmbzlXMXTOQHGcFTYjbm+C8Bv0UUhsSb adamdobrawy@AMILO-Pro-V3205']}}, 'network_config': {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '00:15:5d:ff:62:ee', 'subnets': [{'type': 'static', 'address': '62.181.8.231', 'netmask': '255.255.248.0', 'control': 'auto', 'gateway': '62.181.8.1', 'dns_nameservers': ['8.8.8.8', '8.8.4.4']}]}]}, 'manage_etc_hosts': True}}
2020-07-05 15:28:24,346 - util.py[DEBUG]: Running command ['umount', '/run/cloud-init/tmp/tmpt372qlaa'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:24,422 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data.json (via temporary file /run/cloud-init/tmpa8m0g120) - w: [644] 749 bytes/chars
2020-07-05 15:28:24,504 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmp_rhc6vbw) - w: [600] 749 bytes/chars
2020-07-05 15:28:24,589 - handlers.py[DEBUG]: finish: init-local/search-RbxCloud: SUCCESS: found local data from DataSourceRbxCloud
2020-07-05 15:28:24,644 - stages.py[INFO]: Loaded datasource DataSourceRbxCloud - DataSourceRbxCloud [seed=None]
2020-07-05 15:28:24,693 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False)
2020-07-05 15:28:24,737 - util.py[DEBUG]: Read 2038 bytes from /usr/local/etc/cloud/cloud.cfg
2020-07-05 15:28:24,779 - util.py[DEBUG]: Attempting to load yaml from string of length 2038 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:24,857 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-07-05 15:28:24,907 - util.py[DEBUG]: Read 30 bytes from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-07-05 15:28:24,952 - util.py[DEBUG]: Attempting to load yaml from string of length 30 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:25,011 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-05 15:28:25,066 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:25,126 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-05 15:28:25,168 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-07-05 15:28:25,225 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/5f01f12f8073de470f52eba3'
2020-07-05 15:28:25,306 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/5f01f12f8073de470f52eba3/datasource (quiet=False)
2020-07-05 15:28:25,409 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/datasource - wb: [644] 51 bytes
2020-07-05 15:28:25,516 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 51 bytes
2020-07-05 15:28:25,570 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-07-05 15:28:25,613 - stages.py[DEBUG]: previous iid found to be NO_PREVIOUS_INSTANCE_ID
2020-07-05 15:28:25,657 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 25 bytes
2020-07-05 15:28:25,715 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 25 bytes
2020-07-05 15:28:25,761 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 24 bytes
2020-07-05 15:28:25,819 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 5006 bytes
2020-07-05 15:28:25,863 - main.py[DEBUG]: [local] init will now be targeting instance id: 5f01f12f8073de470f52eba3. new=True
2020-07-05 15:28:25,910 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False)
2020-07-05 15:28:25,946 - util.py[DEBUG]: Read 2038 bytes from /usr/local/etc/cloud/cloud.cfg
2020-07-05 15:28:25,980 - util.py[DEBUG]: Attempting to load yaml from string of length 2038 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:26,045 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-07-05 15:28:26,086 - util.py[DEBUG]: Read 30 bytes from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-07-05 15:28:26,123 - util.py[DEBUG]: Attempting to load yaml from string of length 30 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:26,172 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-05 15:28:26,205 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:26,254 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-05 15:28:26,288 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'>
2020-07-05 15:28:26,326 - cc_set_hostname.py[DEBUG]: Setting the hostname to my-freebsd (my-freebsd)
2020-07-05 15:28:26,361 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False)
2020-07-05 15:28:26,392 - util.py[DEBUG]: Read 41 bytes from /etc/rc.conf
2020-07-05 15:28:26,420 - util.py[DEBUG]: Writing to /etc/rc.conf - wb: [644] 57 bytes
2020-07-05 15:28:26,453 - __init__.py[DEBUG]: Non-persistently setting the system hostname to my-freebsd
2020-07-05 15:28:26,490 - util.py[DEBUG]: Running command ['hostname', 'my-freebsd'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:26,551 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/set-hostname (via temporary file /var/lib/cloud/data/tmpsuh1r222) - w: [644] 53 bytes/chars
2020-07-05 15:28:26,636 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:26,711 - util.py[DEBUG]: Reading from /sys/class/net/hn0/address (quiet=False)
2020-07-05 15:28:26,749 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-07-05 15:28:26,787 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:26,847 - __init__.py[DEBUG]: net: all expected physical devices present
2020-07-05 15:28:26,879 - stages.py[DEBUG]: applying net config names for {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '00:15:5d:ff:62:ee', 'subnets': [{'type': 'static', 'address': '62.181.8.231', 'netmask': '255.255.248.0', 'control': 'auto', 'gateway': '62.181.8.1', 'dns_nameservers': ['8.8.8.8', '8.8.4.4']}]}]}
2020-07-05 15:28:27,002 - stages.py[INFO]: Applying network configuration from ds bringup=False: {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '00:15:5d:ff:62:ee', 'subnets': [{'type': 'static', 'address': '62.181.8.231', 'netmask': '255.255.248.0', 'control': 'auto', 'gateway': '62.181.8.1', 'dns_nameservers': ['8.8.8.8', '8.8.4.4']}]}]}
2020-07-05 15:28:27,134 - __init__.py[DEBUG]: Selected renderer 'freebsd' from priority list: None
2020-07-05 15:28:27,181 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:27,250 - freebsd.py[INFO]: netif service will rename interface hn0 to eth0
2020-07-05 15:28:27,289 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False)
2020-07-05 15:28:27,324 - util.py[DEBUG]: Read 57 bytes from /etc/rc.conf
2020-07-05 15:28:27,361 - util.py[DEBUG]: Writing to /etc/rc.conf - wb: [644] 80 bytes
2020-07-05 15:28:27,401 - freebsd.py[INFO]: Configuring interface eth0
2020-07-05 15:28:27,432 - freebsd.py[DEBUG]: Configuring dev eth0 with 62.181.8.231 / 255.255.248.0
2020-07-05 15:28:27,475 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False)
2020-07-05 15:28:27,511 - util.py[DEBUG]: Read 80 bytes from /etc/rc.conf
2020-07-05 15:28:27,544 - util.py[DEBUG]: Writing to /etc/rc.conf - wb: [644] 131 bytes
2020-07-05 15:28:27,584 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False)
2020-07-05 15:28:27,621 - util.py[DEBUG]: Read 131 bytes from /etc/rc.conf
2020-07-05 15:28:27,653 - util.py[DEBUG]: Writing to /etc/rc.conf - wb: [644] 156 bytes
2020-07-05 15:28:27,693 - util.py[DEBUG]: Reading from /etc/resolv.conf (quiet=False)
2020-07-05 15:28:27,725 - util.py[DEBUG]: Read 19 bytes from /etc/resolv.conf
2020-07-05 15:28:27,753 - util.py[DEBUG]: Writing to /etc/resolv.conf - wb: [644] 38 bytes
2020-07-05 15:28:27,792 - util.py[DEBUG]: Running command ['service', 'netif', 'restart'] with allowed return codes [0] (shell=False, capture=True)
lo0: link state changed to DOWN
hn0: changing name to 'eth0'
lo0: link state changed to UP
2020-07-05 15:28:30,601 - util.py[DEBUG]: Running command ['service', 'routing', 'restart'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-05 15:28:30,758 - main.py[DEBUG]: [local] Exiting. datasource DataSourceRbxCloud [seed=None] not in local mode.
2020-07-05 15:28:30,804 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmparal_61k) - w: [644] 503 bytes/chars
2020-07-05 15:28:30,875 - util.py[DEBUG]: cloud-init mode 'init' took 9.555 seconds (9.55)
2020-07-05 15:28:30,908 - handlers.py[DEBUG]: finish: init-local: SUCCESS: searching for local datasources
Setting up harvesting: [UMA],[FS_ATIME],SWI,INTERRUPT,NET_NG,NET_ETHER,NET_TUN,MOUSE,KEYBOARD,ATTACH,CACHED
Feeding entropy: .
Starting Network: lo0 eth0.
lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> metric 0 mtu 16384
	options=680003<RXCSUM,TXCSUM,LINKSTATE,RXCSUM_IPV6,TXCSUM_IPV6>
	inet6 ::1 prefixlen 128
	inet6 fe80::1%lo0 prefixlen 64 scopeid 0x1
	inet 127.0.0.1 netmask 0xff000000
	groups: lo
	nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
eth0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
	options=8051b<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,TSO4,LRO,LINKSTATE>
	ether 00:15:5d:ff:62:ee
	inet 62.181.8.231 netmask 0xfffff800 broadcast 62.181.15.255
	media: Ethernet autoselect (10Gbase-T <full-duplex>)
	status: active
	nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
Starting devd.
Autoloading module: intpm.ko
intsmb0: <Intel PIIX4 SMBUS Interface> at device 7.3 on pci0
intsmb0: Could not allocate I/O space
device_attach: intsmb0 attach returned 6
add host 127.0.0.1: gateway lo0 fib 0: route already in table
add host ::1: gateway lo0 fib 0: route already in table
add net fe80::: gateway ::1 fib 0: route already in table
add net ff02::: gateway ::1 fib 0: route already in table
add net ::ffff:0.0.0.0: gateway ::1 fib 0: route already in table
add net ::0.0.0.0: gateway ::1 fib 0: route already in table
Generating host.conf.
/usr/local/bin/cloud-init startingWARN: no logging configured! (tried 0 configs)
Setting up basic logging...
Cloud-init v. 20.1 running 'init' at Sun, 05 Jul 2020 15:28:36 +0000. Up 23.855615854263306 seconds.
2020-07-05 15:28:36,804 - util.py[DEBUG]: Cloud-init v. 20.1 running 'init' at Sun, 05 Jul 2020 15:28:36 +0000. Up 23.855615854263306 seconds.
2020-07-05 15:28:36,862 - main.py[DEBUG]: No kernel command line url found.
2020-07-05 15:28:36,895 - main.py[DEBUG]: Closing stdin.
2020-07-05 15:28:36,925 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-07-05 15:28:36,968 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:0
2020-07-05 15:28:37,012 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-05 15:28:37,081 - util.py[DEBUG]: Running command ['netstat', '--route', '--numeric', '--extend'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-05 15:28:37,165 - util.py[DEBUG]: Running command ['netstat', '-A', 'inet6', '--route', '--numeric'] with allowed return codes [0, 1] (shell=False, capture=True)
ci-info: ++++++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++++
ci-info: +--------+------+----------------+------------+-------+-------------------+
ci-info: | Device |  Up  |    Address     |    Mask    | Scope |     Hw-Address    |
ci-info: +--------+------+----------------+------------+-------+-------------------+
ci-info: |  eth0  | True |  62.181.8.231  | 0xfffff800 |   .   | 00:15:5d:ff:62:ee |
ci-info: |  lo0   | True |   127.0.0.1    | 0xff000000 |   .   |         .         |
ci-info: |  lo0   | True |    ::1/128     |     .      |   .   |         .         |
ci-info: |  lo0   | True | fe80::1%lo0/64 |     .      |  0x1  |         .         |
ci-info: +--------+------+----------------+------------+-------+-------------------+
ci-info: 
2020-07-05 15:28:37,506 - 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-07-05 15:28:37,560 - main.py[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early.
2020-07-05 15:28:37,604 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust]
2020-07-05 15:28:37,646 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-07-05 15:28:37,687 - util.py[DEBUG]: Read 5006 bytes from /var/lib/cloud/instance/obj.pkl
2020-07-05 15:28:37,732 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
2020-07-05 15:28:37,769 - util.py[DEBUG]: Read 25 bytes from /run/cloud-init/.instance-id
2020-07-05 15:28:37,801 - stages.py[DEBUG]: restored from cache with run check: DataSourceRbxCloud [seed=None]
2020-07-05 15:28:37,840 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceRbxCloud [seed=None]
2020-07-05 15:28:37,896 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False)
2020-07-05 15:28:37,932 - util.py[DEBUG]: Read 2038 bytes from /usr/local/etc/cloud/cloud.cfg
2020-07-05 15:28:37,965 - util.py[DEBUG]: Attempting to load yaml from string of length 2038 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:38,034 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-07-05 15:28:38,075 - util.py[DEBUG]: Read 30 bytes from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-07-05 15:28:38,113 - util.py[DEBUG]: Attempting to load yaml from string of length 30 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:38,162 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-05 15:28:38,196 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:38,242 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-05 15:28:38,274 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-07-05 15:28:38,308 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/5f01f12f8073de470f52eba3'
2020-07-05 15:28:38,365 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/5f01f12f8073de470f52eba3/datasource (quiet=False)
2020-07-05 15:28:38,413 - util.py[DEBUG]: Read 51 bytes from /var/lib/cloud/instances/5f01f12f8073de470f52eba3/datasource
2020-07-05 15:28:38,456 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/datasource - wb: [644] 51 bytes
2020-07-05 15:28:38,506 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 51 bytes
2020-07-05 15:28:38,550 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-07-05 15:28:38,587 - util.py[DEBUG]: Read 25 bytes from /var/lib/cloud/data/instance-id
2020-07-05 15:28:38,620 - stages.py[DEBUG]: previous iid found to be 5f01f12f8073de470f52eba3
2020-07-05 15:28:38,653 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 25 bytes
2020-07-05 15:28:38,694 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 25 bytes
2020-07-05 15:28:38,733 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 25 bytes
2020-07-05 15:28:38,779 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 5103 bytes
2020-07-05 15:28:38,819 - main.py[DEBUG]: [net] init will now be targeting instance id: 5f01f12f8073de470f52eba3. new=False
2020-07-05 15:28:38,864 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False)
2020-07-05 15:28:38,901 - util.py[DEBUG]: Read 2038 bytes from /usr/local/etc/cloud/cloud.cfg
2020-07-05 15:28:38,937 - util.py[DEBUG]: Attempting to load yaml from string of length 2038 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:39,004 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-07-05 15:28:39,046 - util.py[DEBUG]: Read 30 bytes from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-07-05 15:28:39,084 - util.py[DEBUG]: Attempting to load yaml from string of length 30 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:39,133 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-05 15:28:39,167 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:39,215 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-05 15:28:39,258 - util.py[DEBUG]: Running command ['uname', '-r'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:39,313 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:39,374 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-07-05 15:28:39,414 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: System boot
2020-07-05 15:28:39,457 - util.py[DEBUG]: Running command mount with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:39,510 - util.py[DEBUG]: Fetched {'/dev/gpt/root': {'fstype': 'ufs', 'mountpoint': '/', 'opts': 'noatime'}} mounts from mount
2020-07-05 15:28:39,565 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'vfat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpif_kkurr'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:39,653 - util.py[DEBUG]: Failed mount of '/dev/msdosfs/CLOUDMD' as 'vfat': Unexpected error while running command.
Command: ['mount', '-o', 'ro', '-t', 'vfat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpif_kkurr']
Exit code: 1
Reason: -
Stdout: 
Stderr: mount: /dev/msdosfs/CLOUDMD: Operation not supported by device
2020-07-05 15:28:39,782 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'fat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpif_kkurr'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:39,865 - util.py[DEBUG]: Failed mount of '/dev/msdosfs/CLOUDMD' as 'fat': Unexpected error while running command.
Command: ['mount', '-o', 'ro', '-t', 'fat', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpif_kkurr']
Exit code: 1
Reason: -
Stdout: 
Stderr: mount: /dev/msdosfs/CLOUDMD: Operation not supported by device
2020-07-05 15:28:40,005 - util.py[DEBUG]: Running command ['mount', '-o', 'ro', '-t', 'msdosfs', '/dev/msdosfs/CLOUDMD', '/run/cloud-init/tmp/tmpif_kkurr'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:40,111 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpif_kkurr/cloud.json (quiet=False)
2020-07-05 15:28:40,160 - util.py[DEBUG]: Read 1900 bytes from /run/cloud-init/tmp/tmpif_kkurr/cloud.json
2020-07-05 15:28:40,204 - util.py[DEBUG]: Reading from /run/cloud-init/tmp/tmpif_kkurr/user.data (quiet=True)
2020-07-05 15:28:40,249 - util.py[DEBUG]: Read 0 bytes from /run/cloud-init/tmp/tmpif_kkurr/user.data
2020-07-05 15:28:40,301 - util.py[DEBUG]: Reading from /etc/hosts (quiet=True)
2020-07-05 15:28:40,336 - util.py[DEBUG]: Read 0 bytes from /etc/hosts
2020-07-05 15:28:40,377 - DataSourceRbxCloud.py[DEBUG]: /etc/hosts does not exists - setting manage_etc_hosts to True
2020-07-05 15:28:40,454 - DataSourceRbxCloud.py[DEBUG]: returning DATA object:
2020-07-05 15:28:40,486 - DataSourceRbxCloud.py[DEBUG]: {'userdata': '', 'metadata': {'instance-id': '5f01f12f8073de470f52eba3', 'local-hostname': 'my-freebsd', 'public-keys': []}, 'gratuitous_arp': [{'source': '62.181.8.231', 'destination': '62.181.8.1'}, {'source': '62.181.8.231', 'destination': '62.181.8.3'}, {'source': '62.181.8.231', 'destination': '62.181.8.4'}], 'cfg': {'ssh_pwauth': True, 'disable_root': True, 'system_info': {'default_user': {'name': 'guru', 'gecos': 'guru', 'sudo': ['ALL=(ALL) NOPASSWD:ALL'], 'passwd': '...', 'lock_passwd': False, 'ssh_authorized_keys': ['ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC4XemXNeaQINC9oxgWlhTfkhIngyUahYGHKuDrmV9PUbOvTrO5suUqe9aIOK873uYJVsQ33wkKi73GlF0Ht5FMM+3DbRl3zULnA0PaOOj728KbaCx/ijikGcMC2K3NTBXO1k/f3TDcQiSF92n4Pce6CwNCyeJP0zHecj/5WFsDEvKD1TBpBW0DsJWZ32oTvrZ57/0sH1zo9nxf1KXK9g+fzV2ef31W6X1hQrygKjtQKYSPw4/Nx2R3nuYtDePi3jyM5nRwvXiTeoTb0HNBZ9H8UXvPdBoexxvDqtIJV7S/MpwYh2ptC/UtJYsfI3f6e5tc1xtJAjKWHjc9TolVl9Fb adas@adas-Latitude-E7450', 'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDWBN979NdMeISmieALgwcr6aKJlhIpbTcP35XHotnC35HBK9VluOKNEVAuCBgY9R96qzsRtSXocug21cnqHgyqKlf9qN5YnjnzDRKZxZ+JQngvJ+vzp3HX/rxjMSdQh0vErz4WhFYwAbk51QetvAUD/Pgjw8sbO2kmCMbEovw/6ereYKOZ6NPK96YoLaCLuFnQpw8dbxCjAK/T/V3iVy5ByP4cAsUTXkOxpmHlcy0EskUMgeu4oapMiLKbAmVd3pg+4dHPs/rbvZFv3D0OrRiRxClp2XbuV4M7VzGFVB1M1wdZVCL9di40ZWdByDLCmbIr+JEt7sp4MYeuo3M88zxl adas@adas-Latitude-E7450', 'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDyiqfRnHMBNxOEvO7FAeup7c6EUiFX+rGdtXunE9N6FcHA8swHt90Ip6euRNR1S4h0dIY8Qy9s/orH4+Vh8OizscfY1Looo5w6qiJ1JGSJroEduw4g8I1w7w57sctgPU8XA9U3TQX+f5S8/9wowRehGlQUx6GQJkh+Q1uFsqJ2j8Mju4Ef7wK4KN6i3VGkYqVRbGrIJHUQZrALpJGq2n4Q9mLG6zCopsMqNdkZr1uxI2DkA/TWPIwfiWjsmZjBY2X13O3i+JVDQtsVJu1PqCezCrmiOIC4UgEhHIurZiDyYdcpZVxncThmPmbzlXMXTOQHGcFTYjbm+C8Bv0UUhsSb adamdobrawy@AMILO-Pro-V3205']}}, 'network_config': {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '00:15:5d:ff:62:ee', 'subnets': [{'type': 'static', 'address': '62.181.8.231', 'netmask': '255.255.248.0', 'control': 'auto', 'gateway': '62.181.8.1', 'dns_nameservers': ['8.8.8.8', '8.8.4.4']}]}]}, 'manage_etc_hosts': True}}
2020-07-05 15:28:41,303 - util.py[DEBUG]: Running command ['umount', '/run/cloud-init/tmp/tmpif_kkurr'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:41,378 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data.json (via temporary file /run/cloud-init/tmp90g6z0rw) - w: [644] 749 bytes/chars
2020-07-05 15:28:41,450 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmp5jip_0ht) - w: [600] 749 bytes/chars
2020-07-05 15:28:41,525 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:41,585 - util.py[DEBUG]: Reading from /sys/class/net/eth0/address (quiet=False)
2020-07-05 15:28:41,627 - util.py[DEBUG]: Reading from /sys/class/net/eth0/device/device (quiet=False)
2020-07-05 15:28:41,671 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:41,749 - __init__.py[DEBUG]: net: all expected physical devices present
2020-07-05 15:28:41,783 - stages.py[DEBUG]: applying net config names for {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '00:15:5d:ff:62:ee', 'subnets': [{'type': 'static', 'address': '62.181.8.231', 'netmask': '255.255.248.0', 'control': 'auto', 'gateway': '62.181.8.1', 'dns_nameservers': ['8.8.8.8', '8.8.4.4']}]}]}
2020-07-05 15:28:41,922 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'>
2020-07-05 15:28:41,972 - stages.py[INFO]: Applying network configuration from ds bringup=True: {'version': 1, 'config': [{'type': 'physical', 'name': 'eth0', 'mac_address': '00:15:5d:ff:62:ee', 'subnets': [{'type': 'static', 'address': '62.181.8.231', 'netmask': '255.255.248.0', 'control': 'auto', 'gateway': '62.181.8.1', 'dns_nameservers': ['8.8.8.8', '8.8.4.4']}]}]}
2020-07-05 15:28:42,120 - __init__.py[DEBUG]: Selected renderer 'freebsd' from priority list: None
2020-07-05 15:28:42,171 - util.py[DEBUG]: Running command ['ifconfig', '-a', 'ether'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:42,233 - freebsd.py[INFO]: Configuring interface eth0
2020-07-05 15:28:42,265 - freebsd.py[DEBUG]: Configuring dev eth0 with 62.181.8.231 / 255.255.248.0
2020-07-05 15:28:42,305 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False)
2020-07-05 15:28:42,341 - util.py[DEBUG]: Read 156 bytes from /etc/rc.conf
2020-07-05 15:28:42,372 - util.py[DEBUG]: Writing to /etc/rc.conf - wb: [644] 156 bytes
2020-07-05 15:28:42,412 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False)
2020-07-05 15:28:42,457 - util.py[DEBUG]: Read 156 bytes from /etc/rc.conf
2020-07-05 15:28:42,489 - util.py[DEBUG]: Writing to /etc/rc.conf - wb: [644] 156 bytes
2020-07-05 15:28:42,528 - util.py[DEBUG]: Reading from /etc/resolv.conf (quiet=False)
2020-07-05 15:28:42,565 - util.py[DEBUG]: Read 38 bytes from /etc/resolv.conf
2020-07-05 15:28:42,599 - util.py[DEBUG]: Writing to /etc/resolv.conf - wb: [644] 38 bytes
2020-07-05 15:28:42,639 - util.py[DEBUG]: Running command ['service', 'netif', 'restart'] with allowed return codes [0] (shell=False, capture=True)
in6_purgeaddr: err=65, destination address delete failed
lo0: link state changed to DOWN
lo0: link state changed to UP
2020-07-05 15:28:45,636 - util.py[DEBUG]: Running command ['service', 'routing', 'restart'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-05 15:28:45,800 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource
2020-07-05 15:28:45,843 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource
2020-07-05 15:28:45,890 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/user-data.txt - wb: [600] 0 bytes
2020-07-05 15:28:45,955 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/user-data.txt.i - wb: [600] 308 bytes
2020-07-05 15:28:46,013 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/vendor-data.txt - wb: [600] 0 bytes
2020-07-05 15:28:46,077 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/vendor-data.txt.i - wb: [600] 308 bytes
2020-07-05 15:28:46,137 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False)
2020-07-05 15:28:46,186 - util.py[DEBUG]: Read 53 bytes from /var/lib/cloud/data/set-hostname
2020-07-05 15:28:46,223 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set-hostname
2020-07-05 15:28:46,262 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/consume_data - wb: [644] 24 bytes
2020-07-05 15:28:46,317 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/consume_data'>)
2020-07-05 15:28:46,387 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data
2020-07-05 15:28:46,436 - stages.py[DEBUG]: Added default handler for {'text/cloud-config', 'text/cloud-config-jsonp'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2020-07-05 15:28:46,517 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
2020-07-05 15:28:46,578 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
2020-07-05 15:28:46,639 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']]
2020-07-05 15:28:46,696 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
2020-07-05 15:28:46,750 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2020-07-05 15:28:46,815 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2020-07-05 15:28:46,892 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2020-07-05 15:28:46,953 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2020-07-05 15:28:47,013 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance
2020-07-05 15:28:47,075 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Type': 'text/x-not-multipart', 'Content-Disposition': 'attachment; filename="part-001"'}
2020-07-05 15:28:47,138 - __init__.py[DEBUG]: Empty payload of type text/x-not-multipart
2020-07-05 15:28:47,170 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2020-07-05 15:28:47,236 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/cloud-config.txt - wb: [600] 0 bytes
2020-07-05 15:28:47,287 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2020-07-05 15:28:47,346 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2020-07-05 15:28:47,404 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2020-07-05 15:28:47,459 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance
2020-07-05 15:28:47,511 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data
2020-07-05 15:28:47,560 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data
2020-07-05 15:28:47,596 - stages.py[DEBUG]: no vendordata from datasource
2020-07-05 15:28:47,622 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data
2020-07-05 15:28:47,672 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg (quiet=False)
2020-07-05 15:28:47,709 - util.py[DEBUG]: Read 2038 bytes from /usr/local/etc/cloud/cloud.cfg
2020-07-05 15:28:47,742 - util.py[DEBUG]: Attempting to load yaml from string of length 2038 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:47,809 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-07-05 15:28:47,850 - util.py[DEBUG]: Read 30 bytes from /usr/local/etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-07-05 15:28:47,887 - util.py[DEBUG]: Attempting to load yaml from string of length 30 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:47,936 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-07-05 15:28:47,969 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:48,015 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-05 15:28:48,045 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-07-05 15:28:48,086 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-07-05 15:28:48,125 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:48,174 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-07-05 15:28:48,209 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-07-05 15:28:48,254 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-07-05 15:28:48,288 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-07-05 15:28:48,338 - util.py[DEBUG]: loaded blob returned None, returning default.
WARN: no logging configured! (tried 0 configs)
Setting up basic logging...
2020-07-05 15:28:48,401 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource
2020-07-05 15:28:48,440 - util.py[DEBUG]: Running command ['arping', '-c', '2', '-S', '62.181.8.231', '62.181.8.1'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:50,595 - util.py[DEBUG]: Running command ['arping', '-c', '2', '-S', '62.181.8.231', '62.181.8.3'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:52,774 - util.py[DEBUG]: Running command ['arping', '-c', '2', '-S', '62.181.8.231', '62.181.8.4'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:54,886 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 8864 bytes
2020-07-05 15:28:54,928 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource
2020-07-05 15:28:54,975 - main.py[DEBUG]: no di_report found in config.
2020-07-05 15:28:55,057 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'>
2020-07-05 15:28:55,099 - stages.py[DEBUG]: Running module migrator (<module 'cloudinit.config.cc_migrator' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_migrator.py'>) with frequency always
2020-07-05 15:28:55,177 - handlers.py[DEBUG]: start: init-network/config-migrator: running config-migrator with frequency always
2020-07-05 15:28:55,232 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0x8035b6d50>)
2020-07-05 15:28:55,281 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2020-07-05 15:28:55,324 - handlers.py[DEBUG]: finish: init-network/config-migrator: SUCCESS: config-migrator ran successfully
2020-07-05 15:28:55,370 - stages.py[DEBUG]: Running module seed_random (<module 'cloudinit.config.cc_seed_random' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_seed_random.py'>) with frequency once-per-instance
2020-07-05 15:28:55,508 - handlers.py[DEBUG]: start: init-network/config-seed_random: running config-seed_random with frequency once-per-instance
2020-07-05 15:28:55,587 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_seed_random - wb: [644] 25 bytes
2020-07-05 15:28:55,670 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_seed_random'>)
2020-07-05 15:28:55,738 - cc_seed_random.py[DEBUG]: no command provided
2020-07-05 15:28:55,766 - handlers.py[DEBUG]: finish: init-network/config-seed_random: SUCCESS: config-seed_random ran successfully
2020-07-05 15:28:55,816 - stages.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_bootcmd.py'>) with frequency always
2020-07-05 15:28:55,905 - handlers.py[DEBUG]: start: init-network/config-bootcmd: running config-bootcmd with frequency always
2020-07-05 15:28:55,953 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x8035dc5d0>)
2020-07-05 15:28:56,002 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2020-07-05 15:28:56,041 - handlers.py[DEBUG]: finish: init-network/config-bootcmd: SUCCESS: config-bootcmd ran successfully
2020-07-05 15:28:56,086 - stages.py[DEBUG]: Running module write-files (<module 'cloudinit.config.cc_write_files' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_write_files.py'>) with frequency once-per-instance
2020-07-05 15:28:56,162 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance
2020-07-05 15:28:56,213 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_write_files - wb: [644] 25 bytes
2020-07-05 15:28:56,279 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_write_files'>)
2020-07-05 15:28:56,350 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2020-07-05 15:28:56,394 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files ran successfully
2020-07-05 15:28:56,438 - stages.py[DEBUG]: Running module growpart (<module 'cloudinit.config.cc_growpart' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_growpart.py'>) with frequency always
2020-07-05 15:28:56,508 - handlers.py[DEBUG]: start: init-network/config-growpart: running config-growpart with frequency always
2020-07-05 15:28:56,552 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x8035b6490>)
2020-07-05 15:28:56,594 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg.  Using default: {'mode': 'auto', 'devices': ['/'], 'ignore_growroot_disabled': False}
2020-07-05 15:28:56,651 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:56,712 - util.py[DEBUG]: Running command ['gpart', 'help'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-05 15:28:56,785 - util.py[DEBUG]: Running command ['mount'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:56,844 - util.py[DEBUG]: found line in mount -> devpth: /dev/gpt/root, mount_point: /, fs_type: ufs
2020-07-05 15:28:56,891 - util.py[DEBUG]: Running command ['mount', '-p', '/'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-05 15:28:56,952 - util.py[DEBUG]: Running command ['glabel', 'status', '-s'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:57,047 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:57,117 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:57,170 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:57,222 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-07-05 15:28:57,250 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-07-05 15:28:57,279 - util.py[DEBUG]: Running command ['gpart', 'recover', '/dev/da0'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:57,343 - util.py[DEBUG]: Running command ['gpart', 'resize', '-i', '3', '/dev/da0'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:57,413 - util.py[DEBUG]: resize_devices took 0.628 seconds
2020-07-05 15:28:57,438 - cc_growpart.py[DEBUG]: '/' NOCHANGE: no change necessary (/dev/da0, 3)
2020-07-05 15:28:57,473 - handlers.py[DEBUG]: finish: init-network/config-growpart: SUCCESS: config-growpart ran successfully
2020-07-05 15:28:57,525 - stages.py[DEBUG]: Running module resizefs (<module 'cloudinit.config.cc_resizefs' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_resizefs.py'>) with frequency always
2020-07-05 15:28:57,629 - handlers.py[DEBUG]: start: init-network/config-resizefs: running config-resizefs with frequency always
2020-07-05 15:28:57,692 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x803562b50>)
2020-07-05 15:28:57,948 - util.py[DEBUG]: Running command ['mount'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:58,003 - util.py[DEBUG]: found line in mount -> devpth: /dev/gpt/root, mount_point: /, fs_type: ufs
2020-07-05 15:28:58,044 - util.py[DEBUG]: Running command ['mount', '-p', '/'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-07-05 15:28:58,108 - util.py[DEBUG]: Running command ['glabel', 'status', '-s'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:58,176 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/da0p3 mnt_point=/ path=/
2020-07-05 15:28:58,206 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:58,279 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:58,349 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:58,405 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-07-05 15:28:58,436 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-07-05 15:28:58,474 - util.py[DEBUG]: Running command ['dumpfs', '-m', '/'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:58,550 - util.py[DEBUG]: Running command ['gpart', 'show', '/dev/da0'] with allowed return codes [0] (shell=False, capture=True)
2020-07-05 15:28:58,618 - cc_resizefs.py[DEBUG]: Skip resize filesystem type ufs for /
2020-07-05 15:28:58,653 - handlers.py[DEBUG]: finish: init-network/config-resizefs: SUCCESS: config-resizefs ran successfully
2020-07-05 15:28:58,702 - stages.py[DEBUG]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_set_hostname.py'>) with frequency once-per-instance
2020-07-05 15:28:58,796 - handlers.py[DEBUG]: start: init-network/config-set_hostname: running config-set_hostname with frequency once-per-instance
2020-07-05 15:28:58,847 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_set_hostname - wb: [644] 25 bytes
2020-07-05 15:28:58,914 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_set_hostname'>)
2020-07-05 15:28:58,979 - util.py[DEBUG]: Reading from /var/lib/cloud/data/set-hostname (quiet=False)
2020-07-05 15:28:59,017 - util.py[DEBUG]: Read 53 bytes from /var/lib/cloud/data/set-hostname
2020-07-05 15:28:59,051 - cc_set_hostname.py[DEBUG]: No hostname changes. Skipping set-hostname
2020-07-05 15:28:59,087 - handlers.py[DEBUG]: finish: init-network/config-set_hostname: SUCCESS: config-set_hostname ran successfully
2020-07-05 15:28:59,132 - stages.py[DEBUG]: Running module update_hostname (<module 'cloudinit.config.cc_update_hostname' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_update_hostname.py'>) with frequency always
2020-07-05 15:28:59,208 - handlers.py[DEBUG]: start: init-network/config-update_hostname: running config-update_hostname with frequency always
2020-07-05 15:28:59,258 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x803562850>)
2020-07-05 15:28:59,312 - cc_update_hostname.py[DEBUG]: Updating hostname to my-freebsd (my-freebsd)
2020-07-05 15:28:59,366 - util.py[DEBUG]: Reading from /etc/rc.conf (quiet=False)
2020-07-05 15:28:59,400 - util.py[DEBUG]: Read 156 bytes from /etc/rc.conf
2020-07-05 15:28:59,432 - __init__.py[DEBUG]: Attempting to update hostname to my-freebsd in 1 files
2020-07-05 15:28:59,474 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False)
2020-07-05 15:28:59,515 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-hostname - wb: [644] 87 bytes
2020-07-05 15:28:59,566 - handlers.py[DEBUG]: finish: init-network/config-update_hostname: SUCCESS: config-update_hostname ran successfully
2020-07-05 15:28:59,640 - stages.py[DEBUG]: Running module update_etc_hosts (<module 'cloudinit.config.cc_update_etc_hosts' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_update_etc_hosts.py'>) with frequency always
2020-07-05 15:28:59,739 - handlers.py[DEBUG]: start: init-network/config-update_etc_hosts: running config-update_etc_hosts with frequency always
2020-07-05 15:28:59,806 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x8035b6110>)
2020-07-05 15:28:59,869 - util.py[DEBUG]: Reading from /usr/local/etc/cloud/templates/hosts.freebsd.tmpl (quiet=False)
2020-07-05 15:28:59,947 - util.py[DEBUG]: Read 914 bytes from /usr/local/etc/cloud/templates/hosts.freebsd.tmpl
2020-07-05 15:28:59,994 - templater.py[DEBUG]: Rendering content of '/usr/local/etc/cloud/templates/hosts.freebsd.tmpl' using renderer jinja
2020-07-05 15:29:00,078 - util.py[DEBUG]: Writing to /etc/hosts - wb: [644] 691 bytes
2020-07-05 15:29:00,113 - handlers.py[DEBUG]: finish: init-network/config-update_etc_hosts: SUCCESS: config-update_etc_hosts ran successfully
2020-07-05 15:29:00,161 - stages.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_users_groups.py'>) with frequency once-per-instance
2020-07-05 15:29:00,241 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance
2020-07-05 15:29:00,294 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_users_groups - wb: [644] 25 bytes
2020-07-05 15:29:00,350 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_users_groups'>)
2020-07-05 15:29:00,414 - freebsd.py[INFO]: Adding user guru
2020-07-05 15:29:00,436 - util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['pw', 'useradd', '-n', 'guru', '-d/usr/home/guru', '-m']
2020-07-05 15:29:00,607 - util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: chpasswd for guru
2020-07-05 15:29:00,741 - util.py[DEBUG]: Writing to /etc/sudoers - wb: [440] 167 bytes
2020-07-05 15:29:00,777 - __init__.py[DEBUG]: Added '#includedir /usr/local/etc/sudoers.d' to /etc/sudoers
2020-07-05 15:29:00,816 - util.py[DEBUG]: Writing to /usr/local/etc/sudoers.d/90-cloud-init-users - wb: [440] 118 bytes
2020-07-05 15:29:00,866 - util.py[DEBUG]: Changing the ownership of /usr/home/guru/.ssh to 1001:1001
2020-07-05 15:29:00,903 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-07-05 15:29:00,937 - util.py[DEBUG]: Read 3330 bytes from /etc/ssh/sshd_config
2020-07-05 15:29:00,970 - util.py[DEBUG]: Writing to /usr/home/guru/.ssh/authorized_keys - wb: [600] 1221 bytes
2020-07-05 15:29:01,014 - util.py[DEBUG]: Changing the ownership of /usr/home/guru/.ssh/authorized_keys to 1001:1001
2020-07-05 15:29:01,062 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups ran successfully
2020-07-05 15:29:01,110 - stages.py[DEBUG]: Running module ssh (<module 'cloudinit.config.cc_ssh' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_ssh.py'>) with frequency once-per-instance
2020-07-05 15:29:01,179 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance
2020-07-05 15:29:01,223 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_ssh - wb: [644] 25 bytes
2020-07-05 15:29:01,272 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_ssh'>)
2020-07-05 15:29:01,326 - 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)
Generating public/private rsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_rsa_key.
Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub.
The key fingerprint is:
SHA256:VbcdYhooqN0cuThfHWEp+kD2/RLw4leCEW+usJReTUg root@my-freebsd
The key's randomart image is:
+---[RSA 2048]----+
|      . .Eo++o.. |
|     . *.=+++..o.|
|    o * *.X=. . .|
|   . + *.*=* .   |
|      o+S..o=    |
|      o.+o.o .   |
|       o .. .    |
|                 |
|                 |
+----[SHA256]-----+
2020-07-05 15:29:01,837 - 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)
Generating public/private dsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_dsa_key.
Your public key has been saved in /etc/ssh/ssh_host_dsa_key.pub.
The key fingerprint is:
SHA256:CUdOf2QnkNlCgZnvnQQ604Of4a2W93nzOxAM1XVR39A root@my-freebsd
The key's randomart image is:
+---[DSA 1024]----+
|        o=+*=.+oB|
|       ++.=+.o oE|
|      . o=.o+   o|
|       o=.=..o   |
|        S* B ..  |
|          = +.   |
|           o  .  |
|          + .  +.|
|         . . .oo*|
+----[SHA256]-----+
2020-07-05 15:29:02,144 - 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)
Generating public/private ecdsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key.
Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub.
The key fingerprint is:
SHA256:EIznWuvWO4vpY6amHAAobQHw4t9Qozrks5DF2dTHqR0 root@my-freebsd
The key's randomart image is:
+---[ECDSA 256]---+
|+..  o.          |
|.o ...oo .       |
|= + .=o E        |
|++ +o += .       |
|.o+o.o..S        |
|o+o + .          |
|o=.. o .         |
|..+.. *oo        |
| .oo.*+.o+       |
+----[SHA256]-----+
2020-07-05 15:29:02,412 - 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)
Generating public/private ed25519 key pair.
Your identification has been saved in /etc/ssh/ssh_host_ed25519_key.
Your public key has been saved in /etc/ssh/ssh_host_ed25519_key.pub.
The key fingerprint is:
SHA256:hPgybktf9MEAWts60T4R2x0Gzk4VMGIs5jb3lVjWOcg root@my-freebsd
The key's randomart image is:
+--[ED25519 256]--+
|      o.+ ++=+ . |
|     +oB.B =E.+  |
|    oo+.B =+.. . |
|     .+=.*. o    |
|    o.+oS.+.     |
|   . o o o..     |
|    +   . .      |
|   o o .         |
|    . .          |
+----[SHA256]-----+
2020-07-05 15:29:02,688 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_rsa_key.pub (quiet=False)
2020-07-05 15:29:02,724 - util.py[DEBUG]: Read 397 bytes from /etc/ssh/ssh_host_rsa_key.pub
2020-07-05 15:29:02,757 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ecdsa_key.pub (quiet=False)
2020-07-05 15:29:02,793 - util.py[DEBUG]: Read 177 bytes from /etc/ssh/ssh_host_ecdsa_key.pub
2020-07-05 15:29:02,830 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ed25519_key.pub (quiet=False)
2020-07-05 15:29:02,872 - util.py[DEBUG]: Read 97 bytes from /etc/ssh/ssh_host_ed25519_key.pub
2020-07-05 15:29:02,908 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-07-05 15:29:02,939 - util.py[DEBUG]: Read 3330 bytes from /etc/ssh/sshd_config
2020-07-05 15:29:02,966 - util.py[DEBUG]: Reading from /usr/home/guru/.ssh/authorized_keys (quiet=False)
2020-07-05 15:29:02,999 - util.py[DEBUG]: Read 1221 bytes from /usr/home/guru/.ssh/authorized_keys
2020-07-05 15:29:03,035 - util.py[DEBUG]: Writing to /usr/home/guru/.ssh/authorized_keys - wb: [600] 1221 bytes
2020-07-05 15:29:03,078 - util.py[DEBUG]: Changing the ownership of /usr/home/guru/.ssh/authorized_keys to 1001:1001
2020-07-05 15:29:03,127 - util.py[DEBUG]: Changing the ownership of /root/.ssh to 0:0
2020-07-05 15:29:03,175 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-07-05 15:29:03,207 - util.py[DEBUG]: Read 3330 bytes from /etc/ssh/sshd_config
2020-07-05 15:29:03,239 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 0 bytes
2020-07-05 15:29:03,278 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2020-07-05 15:29:03,314 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh ran successfully
2020-07-05 15:29:03,356 - main.py[DEBUG]: Ran 11 modules with 0 failures
2020-07-05 15:29:03,386 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp3xw5o9ue) - w: [644] 531 bytes/chars
2020-07-05 15:29:03,454 - util.py[DEBUG]: cloud-init mode 'init' took 26.784 seconds (26.78)
2020-07-05 15:29:03,493 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources
Creating and/or trimming log files.
Starting syslogd.
Clearing /tmp (X related).
Mounting late filesystems:.
Updating motd:.
Performing sanity check on sshd configuration.
Starting sshd.
Starting sendmail_submit.
Jul  5 15:29:04 my-freebsd sm-mta[1612]: My unqualified host name (my-freebsd) unknown; sleeping for retry

Jul  5 15:30:04 my-freebsd sm-mta[1612]: unable to qualify my own domain name (my-freebsd) -- using short name

Starting sendmail_msp_queue.
Jul  5 15:30:05 my-freebsd sm-msp-queue[1615]: My unqualified host name (my-freebsd) unknown; sleeping for retry

Jul  5 15:31:05 my-freebsd sm-msp-queue[1615]: unable to qualify my own domain name (my-freebsd) -- using short name

Starting cron.
/usr/local/bin/cloud-init startingWARN: no logging configured! (tried 0 configs)
Setting up basic logging...
Cloud-init v. 20.1 running 'modules:final' at Sun, 05 Jul 2020 15:31:06 +0000. Up 173.5588343143463 seconds.
2020-07-05 15:31:06,497 - util.py[DEBUG]: Cloud-init v. 20.1 running 'modules:final' at Sun, 05 Jul 2020 15:31:06 +0000. Up 173.5588343143463 seconds.
2020-07-05 15:31:06,568 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.freebsd.Distro'>
2020-07-05 15:31:06,606 - stages.py[DEBUG]: Running module package-update-upgrade-install (<module 'cloudinit.config.cc_package_update_upgrade_install' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_package_update_upgrade_install.py'>) with frequency once-per-instance
2020-07-05 15:31:06,712 - handlers.py[DEBUG]: start: modules-final/config-package-update-upgrade-install: running config-package-update-upgrade-install with frequency once-per-instance
2020-07-05 15:31:06,785 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_package_update_upgrade_install - wb: [644] 25 bytes
2020-07-05 15:31:06,845 - helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_package_update_upgrade_install'>)
2020-07-05 15:31:06,920 - handlers.py[DEBUG]: finish: modules-final/config-package-update-upgrade-install: SUCCESS: config-package-update-upgrade-install ran successfully
2020-07-05 15:31:06,979 - stages.py[DEBUG]: Running module salt-minion (<module 'cloudinit.config.cc_salt_minion' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_salt_minion.py'>) with frequency once-per-instance
2020-07-05 15:31:07,061 - handlers.py[DEBUG]: start: modules-final/config-salt-minion: running config-salt-minion with frequency once-per-instance
2020-07-05 15:31:07,117 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_salt_minion - wb: [644] 25 bytes
2020-07-05 15:31:07,171 - helpers.py[DEBUG]: Running config-salt-minion using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_salt_minion'>)
2020-07-05 15:31:07,234 - cc_salt_minion.py[DEBUG]: Skipping module named salt-minion, no 'salt_minion' key in configuration
2020-07-05 15:31:07,277 - handlers.py[DEBUG]: finish: modules-final/config-salt-minion: SUCCESS: config-salt-minion ran successfully
2020-07-05 15:31:07,323 - stages.py[DEBUG]: Running module rightscale_userdata (<module 'cloudinit.config.cc_rightscale_userdata' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_rightscale_userdata.py'>) with frequency once-per-instance
2020-07-05 15:31:07,410 - handlers.py[DEBUG]: start: modules-final/config-rightscale_userdata: running config-rightscale_userdata with frequency once-per-instance
2020-07-05 15:31:07,467 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_rightscale_userdata - wb: [644] 25 bytes
2020-07-05 15:31:07,524 - helpers.py[DEBUG]: Running config-rightscale_userdata using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_rightscale_userdata'>)
2020-07-05 15:31:07,593 - cc_rightscale_userdata.py[DEBUG]: Failed to get raw userdata in module rightscale_userdata
2020-07-05 15:31:07,636 - handlers.py[DEBUG]: finish: modules-final/config-rightscale_userdata: SUCCESS: config-rightscale_userdata ran successfully
2020-07-05 15:31:07,687 - stages.py[DEBUG]: Running module scripts-vendor (<module 'cloudinit.config.cc_scripts_vendor' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_scripts_vendor.py'>) with frequency once-per-instance
2020-07-05 15:31:07,769 - handlers.py[DEBUG]: start: modules-final/config-scripts-vendor: running config-scripts-vendor with frequency once-per-instance
2020-07-05 15:31:07,822 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_scripts_vendor - wb: [644] 24 bytes
2020-07-05 15:31:07,878 - helpers.py[DEBUG]: Running config-scripts-vendor using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_scripts_vendor'>)
2020-07-05 15:31:07,942 - handlers.py[DEBUG]: finish: modules-final/config-scripts-vendor: SUCCESS: config-scripts-vendor ran successfully
2020-07-05 15:31:07,991 - stages.py[DEBUG]: Running module scripts-per-once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once
2020-07-05 15:31:08,071 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once
2020-07-05 15:31:08,122 - util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [644] 25 bytes
2020-07-05 15:31:08,168 - helpers.py[DEBUG]: Running config-scripts-per-once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>)
2020-07-05 15:31:08,225 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once ran successfully
2020-07-05 15:31:08,273 - stages.py[DEBUG]: Running module scripts-per-boot (<module 'cloudinit.config.cc_scripts_per_boot' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_boot.py'>) with frequency always
2020-07-05 15:31:08,354 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-boot: running config-scripts-per-boot with frequency always
2020-07-05 15:31:08,404 - helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x8035cd850>)
2020-07-05 15:31:08,455 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-boot: SUCCESS: config-scripts-per-boot ran successfully
2020-07-05 15:31:08,507 - stages.py[DEBUG]: Running module scripts-per-instance (<module 'cloudinit.config.cc_scripts_per_instance' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_scripts_per_instance.py'>) with frequency once-per-instance
2020-07-05 15:31:08,598 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-instance: running config-scripts-per-instance with frequency once-per-instance
2020-07-05 15:31:08,657 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_scripts_per_instance - wb: [644] 25 bytes
2020-07-05 15:31:08,720 - helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_scripts_per_instance'>)
2020-07-05 15:31:08,790 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-instance: SUCCESS: config-scripts-per-instance ran successfully
2020-07-05 15:31:08,843 - stages.py[DEBUG]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance
2020-07-05 15:31:08,924 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance
2020-07-05 15:31:08,977 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_scripts_user - wb: [644] 24 bytes
2020-07-05 15:31:09,029 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_scripts_user'>)
2020-07-05 15:31:09,090 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully
2020-07-05 15:31:09,131 - stages.py[DEBUG]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequency once-per-instance
2020-07-05 15:31:09,223 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance
2020-07-05 15:31:09,283 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_ssh_authkey_fingerprints - wb: [644] 25 bytes
2020-07-05 15:31:09,343 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_ssh_authkey_fingerprints'>)
2020-07-05 15:31:09,424 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-07-05 15:31:09,456 - util.py[DEBUG]: Read 3330 bytes from /etc/ssh/sshd_config
2020-07-05 15:31:09,488 - util.py[DEBUG]: Reading from /usr/home/guru/.ssh/authorized_keys (quiet=False)
2020-07-05 15:31:09,525 - util.py[DEBUG]: Read 1221 bytes from /usr/home/guru/.ssh/authorized_keys
ci-info: +++++++++++++++++++++++++++++++++++++++Authorized keys from /usr/home/guru/.ssh/authorized_keys for user guru++++++++++++++++++++++++++++++++++++++++
ci-info: +---------+-------------------------------------------------------------------------------------------------+---------+-----------------------------+
ci-info: | Keytype |                                       Fingerprint (sha256)                                      | Options |           Comment           |
ci-info: +---------+-------------------------------------------------------------------------------------------------+---------+-----------------------------+
ci-info: | ssh-rsa | df:9f:a5:8c:9e:e7:3a:d9:ff:69:14:c0:f8:d2:65:d6:8f:ef:9d:eb:c5:83:62:63:a2:67:dc:21:9b:3f:91:1b |    -    |   adas@adas-Latitude-E7450  |
ci-info: | ssh-rsa | 7c:b8:05:ac:9e:c9:aa:92:9a:11:9e:29:d4:bc:11:c3:d0:8a:e5:7a:e4:e4:4a:23:fd:9c:54:ab:36:d2:55:70 |    -    |   adas@adas-Latitude-E7450  |
ci-info: | ssh-rsa | 0f:91:9a:88:4a:cf:17:71:a4:f3:d7:7f:bd:4c:3c:45:35:9e:c3:a2:fb:8c:1b:99:e4:f9:f0:86:e6:47:ee:6e |    -    | adamdobrawy@AMILO-Pro-V3205 |
ci-info: +---------+-------------------------------------------------------------------------------------------------+---------+-----------------------------+
2020-07-05 15:31:10,017 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully
2020-07-05 15:31:10,070 - stages.py[DEBUG]: Running module keys-to-console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance
2020-07-05 15:31:10,159 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance
2020-07-05 15:31:10,213 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_keys_to_console - wb: [644] 25 bytes
2020-07-05 15:31:10,269 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_keys_to_console'>)
2020-07-05 15:31:10,342 - 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)
ec2 1630 - - 
ec2 1630 - - #############################################################
ec2 1630 - - -----BEGIN SSH HOST KEY FINGERPRINTS-----
ec2 1630 - - 1024 SHA256:CUdOf2QnkNlCgZnvnQQ604Of4a2W93nzOxAM1XVR39A root@my-freebsd (DSA)
ec2 1630 - - 256 SHA256:EIznWuvWO4vpY6amHAAobQHw4t9Qozrks5DF2dTHqR0 root@my-freebsd (ECDSA)
ec2 1630 - - 256 SHA256:hPgybktf9MEAWts60T4R2x0Gzk4VMGIs5jb3lVjWOcg root@my-freebsd (ED25519)
ec2 1630 - - 2048 SHA256:VbcdYhooqN0cuThfHWEp+kD2/RLw4leCEW+usJReTUg root@my-freebsd (RSA)
ec2 1630 - - -----END SSH HOST KEY FINGERPRINTS-----
ec2 1630 - - #############################################################
-----BEGIN SSH HOST KEY KEYS-----
ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBGylkE7scXcemCkb+q1QkEsPua6IR8Oe1Ogx5Q7XTKiNHjfCHhwRyh4rxSIz1HP7jY2z41gNRkk6HfB6iozXUhE= root@my-freebsd
ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILAPiwvg81WZXgcPOxIKxvzXCV7O9p/u6XAGJ+Rv9a9F root@my-freebsd
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCuJPxfGijqN7IWRcwBaT0gGaJBPmtw7IhOqFbD3gRUJkZD1V+Bp/Rac27DwnXSROLRbcHJpmIBlRWQHIdZyRAjiLxryootjB+6q54FQTYaTD45dxKM8QIyHwE29TV+YuISdKFtPBxlcrmNcEyT4q0UocLHkF8s8H0pkoAVYZQBtzjnsUhjlg+6anojvdD6FR/eFsuxP8uk0Vod/exDujgVJ25aBbJ8z7h8Qv2hcTF2ON2d+ym9c54vhCBsC9+9oOAvZ6/vG/tHrTKRLjCgqOvSUH3qedsbLpsT4XJqVxdZ+reBKIx2cD/ouCUWjU50VUTKJIITW/i6sxhITGvSfCy9 root@my-freebsd
-----END SSH HOST KEY KEYS-----
2020-07-05 15:31:10,943 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully
2020-07-05 15:31:10,992 - stages.py[DEBUG]: Running module phone-home (<module 'cloudinit.config.cc_phone_home' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_phone_home.py'>) with frequency once-per-instance
2020-07-05 15:31:11,072 - handlers.py[DEBUG]: start: modules-final/config-phone-home: running config-phone-home with frequency once-per-instance
2020-07-05 15:31:11,123 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_phone_home - wb: [644] 25 bytes
2020-07-05 15:31:11,178 - helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_phone_home'>)
2020-07-05 15:31:11,241 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
2020-07-05 15:31:11,286 - handlers.py[DEBUG]: finish: modules-final/config-phone-home: SUCCESS: config-phone-home ran successfully
2020-07-05 15:31:11,333 - stages.py[DEBUG]: Running module final-message (<module 'cloudinit.config.cc_final_message' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_final_message.py'>) with frequency always
2020-07-05 15:31:11,415 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always
2020-07-05 15:31:11,469 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x8035badd0>)
Cloud-init v. 20.1 finished at Sun, 05 Jul 2020 15:31:11 +0000. Datasource DataSourceRbxCloud [seed=None].  Up 178.67786598205566 seconds
2020-07-05 15:31:11,590 - util.py[DEBUG]: Cloud-init v. 20.1 finished at Sun, 05 Jul 2020 15:31:11 +0000. Datasource DataSourceRbxCloud [seed=None].  Up 178.67786598205566 seconds
2020-07-05 15:31:11,709 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 63 bytes
2020-07-05 15:31:11,805 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully
2020-07-05 15:31:11,863 - stages.py[DEBUG]: Running module power-state-change (<module 'cloudinit.config.cc_power_state_change' from '/usr/local/lib/python3.7/site-packages/cloudinit/config/cc_power_state_change.py'>) with frequency once-per-instance
2020-07-05 15:31:11,972 - handlers.py[DEBUG]: start: modules-final/config-power-state-change: running config-power-state-change with frequency once-per-instance
2020-07-05 15:31:12,031 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_power_state_change - wb: [644] 25 bytes
2020-07-05 15:31:12,092 - helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/var/lib/cloud/instances/5f01f12f8073de470f52eba3/sem/config_power_state_change'>)
2020-07-05 15:31:12,171 - cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing
2020-07-05 15:31:12,206 - handlers.py[DEBUG]: finish: modules-final/config-power-state-change: SUCCESS: config-power-state-change ran successfully
2020-07-05 15:31:12,259 - main.py[DEBUG]: Ran 13 modules with 0 failures
2020-07-05 15:31:12,294 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpyvv3gzsd) - w: [644] 558 bytes/chars
2020-07-05 15:31:12,372 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmphnzt5dmj) - w: [644] 81 bytes/chars
2020-07-05 15:31:12,444 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
2020-07-05 15:31:12,496 - util.py[DEBUG]: cloud-init mode 'modules' took 6.108 seconds (6.11)
2020-07-05 15:31:12,529 - handlers.py[DEBUG]: finish: modules-final: SUCCESS: running modules for final
Configuring vt: blanktime.
Autoloading module: intpm.ko
Starting background file system checks in 60 seconds.

Sun Jul  5 15:31:12 UTC 2020


FreeBSD/amd64 (my-freebsd) (ttyu0)



login: 

Here is content of /etc/hosts:

# Your system has configured 'manage_etc_hosts' as True.
# As a result, if you wish for changes to this file to persist
# then you will need to either
# a.) make changes to the master file in /etc/cloud/templates/hosts.freebsd.tmpl
# b.) change or remove the value of 'manage_etc_hosts' in
#     /etc/cloud/cloud.cfg or cloud-config from user-data
# 
# The following lines are desirable for IPv4 capable hosts
127.0.0.1 my-freebsd my-freebsd
127.0.0.1 localhost.localdomain localhost
127.0.0.1 localhost4.localdomain4 localhost4

# The following lines are desirable for IPv6 capable hosts
::1 my-freebsd my-freebsd
::1 localhost.localdomain localhost
::1 localhost6.localdomain6 localhost6

It match to template of /etc/hosts already available ( https://github.com/canonical/cloud-init/blob/7c88f96245535aacfac9b0b04d9c0d82ac2067f4/templates/hosts.freebsd.tmpl ) and introduced 6 years ago by @RaginBajin .

@igalic
Copy link
Collaborator

igalic commented Jul 5, 2020

Here's the current of FreeBSD's /etc/hosts: https://github.com/freebsd/freebsd/blob/HEAD/lib/libc/net/hosts

note the preference of IPv6 and IPv4 is now reversed.
do you wanna update that file too, while you're at it?
I'll try to find the other BSDs as well

unrelatedly, what's up with those mount errors?

@ad-m
Copy link
Contributor Author

ad-m commented Jul 5, 2020

note the preference of IPv6 and IPv4 is now reversed.
do you wanna update that file too, while you're at it?

Yes, I will update source branch. I would like to point out that my knowledge of the FreeBSD environment is limited and I am asking for limited confidence.

unrelatedly, what's up with those mount errors?

Mount errors is regarding datasource discovery here: https://github.com/canonical/cloud-init/blob/master/cloudinit/sources/DataSourceRbxCloud.py#L81-L85 I works for RbxCloud and will be happy to optimize the process if you have suggestions.

@igalic
Copy link
Collaborator

igalic commented Jul 5, 2020

note the preference of IPv6 and IPv4 is now reversed.
do you wanna update that file too, while you're at it?

Yes, I will update source branch. I would like to point out that my knowledge of the FreeBSD environment is limited and I am asking for limited confidence.

https://github.com/NetBSD/src/blob/HEAD/etc/hosts ← NetBSD is the same
(and i have no idea what OpenBSD does 🤷‍♀️️, so, uhm…)

unrelatedly, what's up with those mount errors?

Mount errors is regarding datasource discovery here: https://github.com/canonical/cloud-init/blob/master/cloudinit/sources/DataSourceRbxCloud.py#L81-L85 I works for RbxCloud and will be happy to optimize the process if you have suggestions.

nah, let's leave this for now
we could push the resolution of filesystem names into the distro
but, def not today.

Copy link
Collaborator

@igalic igalic left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

almost good to go

config/cloud.cfg.tmpl Outdated Show resolved Hide resolved
@ad-m
Copy link
Contributor Author

ad-m commented Jul 5, 2020

NetBSD is the same

I have no experience in NetBSD. I fully trust your comments.

- update_etc_hosts
{% if variant.endswith("bsd") %}
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the logic here needs inverting (to match its previous state); we should emit these lines only if we are not on BSD, right?

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

duh

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ad-m It was only this line that needed updating, to match the previous meaning. We are generalising variant not in [...] so this should be:

Suggested change
{% if variant.endswith("bsd") %}
{% if not variant.endswith("bsd") %}

Copy link
Collaborator

@OddBloke OddBloke left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for looking at this! I have one inline comment.

@OddBloke OddBloke self-assigned this Jul 6, 2020
Copy link
Collaborator

@OddBloke OddBloke left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This still needs work; I've tried rephrasing my suggestion(s), let me know if you need further clarification!

- update_etc_hosts
{% if variant.endswith("bsd") %}
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ad-m It was only this line that needed updating, to match the previous meaning. We are generalising variant not in [...] so this should be:

Suggested change
{% if variant.endswith("bsd") %}
{% if not variant.endswith("bsd") %}

@@ -33,7 +33,7 @@ ssh_pwauth: 0
# This will cause the set+update hostname module to not operate (if true)
preserve_hostname: false

{% if variant.endswith("bsd") %}
{% if not variant.endswith("bsd") %}
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is incorrect; this stanza is only present to workaround issues seen on BSDs, so it should only be emitted under the condition that was already here.

(If the issue you were fixing was that RbxCloud wasn't being found on *BSD, then you'll want to add it to the datasource_list that this if clause guards.)

@ad-m
Copy link
Contributor Author

ad-m commented Jul 6, 2020

@OddBloke, Sorry, I corrected the wrong line quickly from the editor. When I saw error , you were able to publish post with new comments before I pushed the rebased changes.

@OddBloke
Copy link
Collaborator

OddBloke commented Jul 7, 2020

@OddBloke, Sorry, I corrected the wrong line quickly from the editor. When I saw error , you were able to publish post with new comments before I pushed the rebased changes.

No worries, thanks for the updates!

Copy link
Collaborator

@OddBloke OddBloke left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This LGTM now, thank you! @igalic, are you happy with this now?

Copy link
Collaborator

@igalic igalic left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💜

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants