Please test autoinstalls for 20.04!

Server
67

I’m using cobbler to netboot 20.04. I have the autoinstall mostly work however running in to a few issues.

#1) apt isn’t using my defined mirror. I’ve tried multiple iterations of the syntax however during install it uses the the default archive.ubuntu.com rather then my local repo. In addition I tried using a late command to place the sources.list I wanted however cloud-int overwrites it on first boot changing it back to the default. I’ve tried preserve_sources_list true and false and each time it’s overwritten on first boot. Below are the stanza’s I’ve tried. Does anyone have a version of a autoinstall config with a working apt stanza?

Versions I’ve tried based on the Ubuntu and Cloud-int docs.

apt:
preserve_sources_list: false
primary:
- arches:
- amd64
- i386
uri: “MY URL”

apt:
preserve_sources_list: false
primary:
- arches:
- amd64
- i386
- uri: “MY URL”

apt:
preserve_sources_list: true
primary:
- arches: [amd64, i386]
uri: MY URL

#2). Is it possible to change the timezone during the autoinstall process? I’ve tried the cloud-init variable timezone: “TIMEZONE” however that doesn’t do anything during installation and it doesn’t get passed to the cloud-config.tx file in /var/lib/cloud/instances/XXXX/ I see my ssh key and identity information so it looks like there’s something in place to move data in to that file.

#3). Static network config. I’m having the same problem another user mentioned where the static network config is being replaced by a generic dhcp config once the system boots. For now I’ve used late-commands to put in a static netplan config so the system will be pingable once it boots. Autoinstall network config below.

network:
network:
version: 2
ethernets:
eth0:
match:
macaddress: $mac_address_eth0
set-name: eth0
addresses: [ $ip_address_eth0/$hmgmt_prefix ]
gateway4: $gateway

During the install netplan is configured properly with a static IP/GW, however once booted Netplan looks like this

network:
ethernets:
eth0:
dhcp4: true
version: 2

68 
$ cat user-data
#cloud-config
autoinstall:
  version: 1
  ssh:
    install-server: true
  identity:
    hostname: duvaniste
    username: zarko
    password: "$6$exDY1mhS4KUYCE/2$zmn9ToZwTKLhCw.b4/b.ZRTIZM30JZ4QrOQ2aOXJ8yk96xpcCof0kxKwuX1kqLG/ygbJ1f8wxED22bTL4F46P0"

I have a problem cannot login hostname is ok set, but I am not sure if username or password or both are not good applied. Here crypted password is “ubuntu”. Tryied many times to do reinstallation and always everything is ok just I cannot login.

Do you know what I am doing wrong? How to access logs, tried with rsyslog to see on another machine but without success when I configure report to rsyslog by instruction from here https://wiki.ubuntu.com/FoundationsTeam/AutomatedServerInstalls/ConfigReference#reporting it doesn’t work autoinstall, instead regular install is starting without asking for autoinstall, looks like something is wrong with config. Changed just ip address of my machine and test is started on VM.

1 Like
69

04%20%5BRunning%5D%20-%20Oracle%20VM%20VirtualBox_214
Ubuntu20.04 [Running] - Oracle VM VirtualBox_214.png956×1033 48.3 KB

Here is screenshot of the last screen, it says user ubuntu on 2 places.

70

Definitely creating user is not working with CIDATA iso image, but works if I repack installation iso with https://gist.github.com/s3rj1k/55b10cd20f31542046018fcce32f103e.

With CIDATA iso it creates user ubuntu, I guess this is default behavior when user in user-data is failed to create for some reasons.

1 Like
71

Hello! I’m wondering, is NoCloud the only supported data source for automated installs at the moment?

I’ve been trying to get the OVF data source to work, so far with no luck.

To summarise my environment:

  • VMware ESXi 6.7U3 in standalone mode.
  • Virtual machines are deployed using a custom OVF.
  • Ubuntu 20.04 live server ISO is used to install the operating system.
  • Cloud-init user data is injected into the OVF environment to be loaded through the VMWare guestinfo transport.

OVF file (ubuntu.ovf), user data (cloud-config.yaml) and full cloud-init log (cloud-init.log) are at the bottom of this post.

With all that said, it doesn’t seem like cloud-init even attempts to get anything from the OVF data source. It tries NoCloud and settles with that, even though (from what I figure) it’s empty.

2020-05-03 12:40:52,631 - __init__.py[DEBUG]: Looking for data source in: ['NoCloud', 'OVF', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2020-05-03 12:40:52,652 - __init__.py[DEBUG]: Searching for local data source in: ['DataSourceNoCloud', 'DataSourceOVF']
2020-05-03 12:40:52,652 - handlers.py[DEBUG]: start: init-local/search-NoCloud: searching for local data from DataSourceNoCloud
...
2020-05-03 12:41:13,143 - util.py[DEBUG]: Cloud-init v. 20.1-10-g71af48df-0ubuntu5 finished at Sun, 03 May 2020 12:41:13 +0000. Datasource DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud][dsmode=net].  Up 36.32 seconds

The OVF environment data is definitely accessible from the virtual machine:

root@ubuntu-server:/var/log# vmware-rpctool 'info-get guestinfo.ovfEnv'
<?xml version="1.0" encoding="UTF-8"?><Environment oe:id="" ve:esxId="39" xmlns="http://schemas.dmtf.org/ovf/environment/1" xmlns:oe="http://schemas.dmtf.org/ovf/environment/1" xmlns:ve="http://www.vmware.com/schema/ovfenv" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"><PlatformSection><Kind>VMware ESXi</Kind><Version>6.7.0</Version><Vendor>VMware, Inc.</Vendor><Locale>US</Locale></PlatformSection><PropertySection><Property oe:key="hostname" oe:value="testvm" /><Property oe:key="user-data" oe:value="I2Nsb3VkLWNvbmZpZwphdXRvaW5zdGFsbDoKICB2ZXJzaW9uOiAxCiAgcmVmcmVzaC1pbnN0YWxsZXI6CiAgICB1cGRhdGU6IHllcwogIGFwdDoKICAgIHByaW1hcnk6CiAgICAgIC0gYXJjaGVzOiBbaTM4NiwgYW1kNjRdCiAgICAgICAgdXJpOiAiaHR0cHM6Ly9taXJyb3IueWFuZGV4LnJ1L3VidW50dSIKICAgICAgLSBhcmNoZXM6IFtkZWZhdWx0XQogICAgICAgIHVyaTogImh0dHBzOi8vbWlycm9yLnlhbmRleC5ydS91YnVudHUtcG9ydHMiCiAgaWRlbnRpdHk6CiAgICBob3N0bmFtZTogdGVzdHZtCiAgICByZWFsbmFtZTogRmlyc3RuYW1lIExhc3RuYW1lCiAgICB1c2VybmFtZTogdXNlcm5hbWUKICAgIHBhc3N3b3JkOiAiJDYkLi4uIgogIHNzaDoKICAgIGluc3RhbGwtc2VydmVyOiB5ZXMKICAgIGFsbG93LXB3OiBubwogIHVzZXItZGF0YToKICAgIHVzZXJzOgogICAgICAtIG5hbWU6IGFuc2libGUKICAgICAgICBnZWNvczogQW5zaWJsZQogICAgICAgIHN1ZG86ICJBTEw9KEFMTCkgTk9QQVNTV0Q6QUxMIgogICAgICAgIHNzaF9hdXRob3JpemVkX2tleXM6CiAgICAgICAgICAtICJzc2gtZWQyNTUxOSBBQUFBLi4uIgogICAgcGFja2FnZV91cGRhdGU6IHllcwogICAgcGFja2FnZV91cGdyYWRlOiB5ZXMK" /></PropertySection></Environment>

Am I attempting an unsupported configuration? Can I perhaps somehow force it to use the OVF data source?

Any help is appreciated.

ubuntu.ovf 
<?xml version="1.0" encoding="UTF-8"?>
<Envelope vmw:buildId="build-15160138" xmlns="http://schemas.dmtf.org/ovf/envelope/1" xmlns:cim="http://schemas.dmtf.org/wbem/wscim/1/common" xmlns:ovf="http://schemas.dmtf.org/ovf/envelope/1" xmlns:rasd="http://schemas.dmtf.org/wbem/wscim/1/cim-schema/2/CIM_ResourceAllocationSettingData" xmlns:vmw="http://www.vmware.com/schema/ovf" xmlns:vssd="http://schemas.dmtf.org/wbem/wscim/1/cim-schema/2/CIM_VirtualSystemSettingData" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <References></References>
  <DiskSection>
    <Info>Virtual disk information</Info>
    <Disk ovf:capacity="5" ovf:capacityAllocationUnits="byte * 2^30" ovf:diskId="vmdisk1" ovf:format="http://www.vmware.com/interfaces/specifications/vmdk.html#streamOptimized" ovf:populatedSize="0"/>
  </DiskSection>
  <NetworkSection>
    <Info>The list of logical networks</Info>
    <Network ovf:name="Internal">
      <Description>Internal network</Description>
    </Network>
  </NetworkSection>
  <VirtualSystem ovf:id="UbuntuVM">
    <Info>A virtual machine</Info>
    <Name>UbuntuVM</Name>
    <ProductSection>
      <Info>Describes the virtual machine</Info>
      <Product>Ubuntu Server Automated</Product>
      <Vendor>Forst</Vendor>
      <Version>20.04-1</Version>

      <Property ovf:key="instance-id" ovf:type="string" ovf:userConfigurable="true" ovf:value="id-ovf">
        <Label>A Unique Instance ID for this instance</Label>
        <Description>Specifies the instance id.  This is required and used to determine if the machine should take "first boot" actions</Description>
      </Property>
      <Property ovf:key="hostname" ovf:type="string" ovf:userConfigurable="true" ovf:value="ubuntuguest">
          <Description>Specifies the hostname for the appliance</Description>
      </Property>
      <Property ovf:key="seedfrom" ovf:type="string" ovf:userConfigurable="true">
          <Label>Url to seed instance data from</Label>
          <Description>This field is optional, but indicates that the instance should 'seed' user-data and meta-data from the given url.  If set to 'http://tinyurl.com/sm-' is given, meta-data will be pulled from http://tinyurl.com/sm-meta-data and user-data from http://tinyurl.com/sm-user-data.  Leave this empty if you do not want to seed from a url.</Description>
      </Property>
      <Property ovf:key="public-keys" ovf:type="string" ovf:userConfigurable="true" ovf:value="">
          <Label>ssh public keys</Label>
          <Description>This field is optional, but indicates that the instance should populate the default user's 'authorized_keys' with this value</Description>
      </Property>
      <Property ovf:key="user-data" ovf:type="string" ovf:userConfigurable="true" ovf:value="">
          <Label>Encoded user-data</Label>
          <Description>In order to fit into a xml attribute, this value is base64 encoded . It will be decoded, and then processed normally as user-data.</Description>
      </Property>
      <Property ovf:key="password" ovf:type="string" ovf:userConfigurable="true" ovf:value="">
          <Label>Default User's password</Label>
          <Description>If set, the default user's password will be set to this value to allow password based login.  The password will be good for only a single login.  If set to the string 'RANDOM' then a random password will be generated, and written to the console.</Description>
      </Property>
    </ProductSection>
    <AnnotationSection ovf:required="false">
        <Info>A human-readable annotation</Info>
        <Annotation>Ubuntu Server Automated</Annotation>
    </AnnotationSection>
    <OperatingSystemSection ovf:id="94" vmw:osType="ubuntu64Guest">
      <Info>The kind of installed guest operating system</Info>
    </OperatingSystemSection>
    <VirtualHardwareSection>
      <Info>Virtual hardware requirements</Info>
      <System>
        <vssd:ElementName>Virtual Hardware Family</vssd:ElementName>
        <vssd:InstanceID>0</vssd:InstanceID>
        <vssd:VirtualSystemIdentifier>UbuntuVM</vssd:VirtualSystemIdentifier>
        <vssd:VirtualSystemType>vmx-15</vssd:VirtualSystemType>
      </System>
      <Item>
        <rasd:AllocationUnits>hertz * 10^6</rasd:AllocationUnits>
        <rasd:Description>Number of Virtual CPUs</rasd:Description>
        <rasd:ElementName>1 virtual CPU(s)</rasd:ElementName>
        <rasd:InstanceID>1</rasd:InstanceID>
        <rasd:ResourceType>3</rasd:ResourceType>
        <rasd:VirtualQuantity>1</rasd:VirtualQuantity>
      </Item>
      <Item>
        <rasd:AllocationUnits>byte * 2^20</rasd:AllocationUnits>
        <rasd:Description>Memory Size</rasd:Description>
        <rasd:ElementName>1024MB of memory</rasd:ElementName>
        <rasd:InstanceID>2</rasd:InstanceID>
        <rasd:ResourceType>4</rasd:ResourceType>
        <rasd:VirtualQuantity>1024</rasd:VirtualQuantity>
      </Item>
      <Item>
        <rasd:Address>0</rasd:Address>
        <rasd:Description>SATA Controller</rasd:Description>
        <rasd:ElementName>SATA Controller 0</rasd:ElementName>
        <rasd:InstanceID>3</rasd:InstanceID>
        <rasd:ResourceSubType>vmware.sata.ahci</rasd:ResourceSubType>
        <rasd:ResourceType>20</rasd:ResourceType>
      </Item>
      <Item>
        <rasd:Address>0</rasd:Address>
        <rasd:Description>SCSI Controller</rasd:Description>
        <rasd:ElementName>SCSI Controller 0</rasd:ElementName>
        <rasd:InstanceID>4</rasd:InstanceID>
        <rasd:ResourceSubType>VirtualSCSI</rasd:ResourceSubType>
        <rasd:ResourceType>6</rasd:ResourceType>
      </Item>
      <Item>
        <rasd:Address>1</rasd:Address>
        <rasd:Description>IDE Controller</rasd:Description>
        <rasd:ElementName>VirtualIDEController 1</rasd:ElementName>
        <rasd:InstanceID>5</rasd:InstanceID>
        <rasd:ResourceType>5</rasd:ResourceType>
      </Item>
      <Item>
        <rasd:Address>0</rasd:Address>
        <rasd:Description>IDE Controller</rasd:Description>
        <rasd:ElementName>VirtualIDEController 0</rasd:ElementName>
        <rasd:InstanceID>6</rasd:InstanceID>
        <rasd:ResourceType>5</rasd:ResourceType>
      </Item>
      <Item ovf:required="false">
        <rasd:AutomaticAllocation>false</rasd:AutomaticAllocation>
        <rasd:ElementName>VirtualVideoCard</rasd:ElementName>
        <rasd:InstanceID>7</rasd:InstanceID>
        <rasd:ResourceType>24</rasd:ResourceType>
        <vmw:Config ovf:required="false" vmw:key="useAutoDetect" vmw:value="true"/>
        <vmw:Config ovf:required="false" vmw:key="videoRamSizeInKB" vmw:value="4096"/>
        <vmw:Config ovf:required="false" vmw:key="enable3DSupport" vmw:value="false"/>
        <vmw:Config ovf:required="false" vmw:key="use3dRenderer" vmw:value="automatic"/>
        <vmw:Config ovf:required="false" vmw:key="graphicsMemorySizeInKB" vmw:value="262144"/>
      </Item>
      <Item ovf:required="false">
        <rasd:AutomaticAllocation>false</rasd:AutomaticAllocation>
        <rasd:ElementName>VirtualVMCIDevice</rasd:ElementName>
        <rasd:InstanceID>8</rasd:InstanceID>
        <rasd:ResourceSubType>vmware.vmci</rasd:ResourceSubType>
        <rasd:ResourceType>1</rasd:ResourceType>
        <vmw:Config ovf:required="false" vmw:key="allowUnrestrictedCommunication" vmw:value="false"/>
      </Item>
      <Item ovf:required="false">
        <rasd:AddressOnParent>0</rasd:AddressOnParent>
        <rasd:AutomaticAllocation>false</rasd:AutomaticAllocation>
        <rasd:ElementName>CD-ROM 1</rasd:ElementName>
        <rasd:InstanceID>9</rasd:InstanceID>
        <rasd:Parent>3</rasd:Parent>
        <rasd:ResourceSubType>vmware.cdrom.atapi</rasd:ResourceSubType>
        <rasd:ResourceType>15</rasd:ResourceType>
        <vmw:Config ovf:required="false" vmw:key="connectable.allowGuestControl" vmw:value="true"/>
      </Item>
      <Item>
        <rasd:AddressOnParent>0</rasd:AddressOnParent>
        <rasd:ElementName>Hard Disk 1</rasd:ElementName>
        <rasd:HostResource>ovf:/disk/vmdisk1</rasd:HostResource>
        <rasd:InstanceID>10</rasd:InstanceID>
        <rasd:Parent>4</rasd:Parent>
        <rasd:ResourceType>17</rasd:ResourceType>
        <vmw:Config ovf:required="false" vmw:key="backing.writeThrough" vmw:value="false"/>
      </Item>
      <Item>
        <rasd:AddressOnParent>7</rasd:AddressOnParent>
        <rasd:AutomaticAllocation>true</rasd:AutomaticAllocation>
        <rasd:Connection>Internal</rasd:Connection>
        <rasd:Description>VmxNet3 ethernet adapter on &quot;Internal&quot;</rasd:Description>
        <rasd:ElementName>Ethernet 1</rasd:ElementName>
        <rasd:InstanceID>11</rasd:InstanceID>
        <rasd:ResourceSubType>VmxNet3</rasd:ResourceSubType>
        <rasd:ResourceType>10</rasd:ResourceType>
        <vmw:Config ovf:required="false" vmw:key="wakeOnLanEnabled" vmw:value="false"/>
        <vmw:Config ovf:required="false" vmw:key="connectable.allowGuestControl" vmw:value="true"/>
      </Item>
      <vmw:Config ovf:required="false" vmw:key="cpuHotAddEnabled" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="cpuHotRemoveEnabled" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="memoryHotAddEnabled" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="firmware" vmw:value="efi"/>
      <vmw:Config ovf:required="false" vmw:key="cpuAllocation.shares.shares" vmw:value="1000"/>
      <vmw:Config ovf:required="false" vmw:key="cpuAllocation.shares.level" vmw:value="normal"/>
      <vmw:Config ovf:required="false" vmw:key="tools.syncTimeWithHost" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="tools.afterPowerOn" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="tools.afterResume" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="tools.beforeGuestShutdown" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="tools.beforeGuestStandby" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="tools.toolsUpgradePolicy" vmw:value="manual"/>
      <vmw:Config ovf:required="false" vmw:key="powerOpInfo.powerOffType" vmw:value="soft"/>
      <vmw:Config ovf:required="false" vmw:key="powerOpInfo.resetType" vmw:value="soft"/>
      <vmw:Config ovf:required="false" vmw:key="powerOpInfo.suspendType" vmw:value="soft"/>
      <vmw:Config ovf:required="false" vmw:key="nestedHVEnabled" vmw:value="false"/>
      <vmw:Config ovf:required="false" vmw:key="virtualICH7MPresent" vmw:value="false"/>
      <vmw:Config ovf:required="false" vmw:key="virtualSMCPresent" vmw:value="false"/>
      <vmw:Config ovf:required="false" vmw:key="flags.vvtdEnabled" vmw:value="false"/>
      <vmw:Config ovf:required="false" vmw:key="flags.vbsEnabled" vmw:value="false"/>
      <vmw:Config ovf:required="false" vmw:key="bootOptions.efiSecureBootEnabled" vmw:value="true"/>
      <vmw:Config ovf:required="false" vmw:key="powerOpInfo.standbyAction" vmw:value="checkpoint"/>
      <vmw:ExtraConfig ovf:required="false" vmw:key="nvram" vmw:value="UbuntuVM.nvram"/>
      <vmw:ExtraConfig ovf:required="false" vmw:key="svga.autodetect" vmw:value="TRUE"/>
      <vmw:ExtraConfig ovf:required="false" vmw:key="tools.guest.desktop.autolock" vmw:value="TRUE"/>
      <vmw:ExtraConfig ovf:required="false" vmw:key="RemoteDisplay.maxConnections" vmw:value="-1"/>
    </VirtualHardwareSection>
  </VirtualSystem>
</Envelope>
cloud-config.yaml 
#cloud-config
autoinstall:
  version: 1
  refresh-installer:
    update: yes
  apt:
    primary:
      - arches: [i386, amd64]
        uri: "https://mirror.yandex.ru/ubuntu"
      - arches: [default]
        uri: "https://mirror.yandex.ru/ubuntu-ports"
  identity:
    hostname: testvm
    realname: Firstname Lastname
    username: username
    password: "$6$..."
  ssh:
    install-server: yes
    allow-pw: no
  user-data:
    users:
      - name: ansible
        gecos: Ansible
        sudo: "ALL=(ALL) NOPASSWD:ALL"
        ssh_authorized_keys:
          - "ssh-ed25519 AAAA..."
    package_update: yes
    package_upgrade: yes
cloud-init.log 
2020-05-03 12:40:52,619 - util.py[DEBUG]: Cloud-init v. 20.1-10-g71af48df-0ubuntu5 running 'init-local' at Sun, 03 May 2020 12:40:52 +0000. Up 15.78 seconds.
2020-05-03 12:40:52,619 - main.py[DEBUG]: No kernel command line url found.
2020-05-03 12:40:52,619 - main.py[DEBUG]: Closing stdin.
2020-05-03 12:40:52,622 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-05-03 12:40:52,623 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 104:4
2020-05-03 12:40:52,623 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
2020-05-03 12:40:52,623 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net
2020-05-03 12:40:52,623 - handlers.py[DEBUG]: start: init-local/check-cache: attempting to read from cache [check]
2020-05-03 12:40:52,623 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-05-03 12:40:52,623 - stages.py[DEBUG]: no cache found
2020-05-03 12:40:52,623 - handlers.py[DEBUG]: finish: init-local/check-cache: SUCCESS: no cache found
2020-05-03 12:40:52,623 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-05-03 12:40:52,628 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2020-05-03 12:40:52,631 - __init__.py[DEBUG]: Looking for data source in: ['NoCloud', 'OVF', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2020-05-03 12:40:52,652 - __init__.py[DEBUG]: Searching for local data source in: ['DataSourceNoCloud', 'DataSourceOVF']
2020-05-03 12:40:52,652 - handlers.py[DEBUG]: start: init-local/search-NoCloud: searching for local data from DataSourceNoCloud
2020-05-03 12:40:52,652 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceNoCloud.DataSourceNoCloud'>
2020-05-03 12:40:52,652 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: New instance first boot
2020-05-03 12:40:52,652 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:52,657 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:52,658 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:52,659 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-05-03 12:40:52,660 - util.py[DEBUG]: Read 273 bytes from /proc/1/environ
2020-05-03 12:40:52,660 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-05-03 12:40:52,660 - util.py[DEBUG]: Read 1349 bytes from /proc/self/status
2020-05-03 12:40:52,660 - util.py[DEBUG]: querying dmi data /sys/class/dmi/id/product_serial
2020-05-03 12:40:52,660 - util.py[DEBUG]: Reading from /sys/class/dmi/id/product_serial (quiet=False)
2020-05-03 12:40:52,660 - util.py[DEBUG]: Read 55 bytes from /sys/class/dmi/id/product_serial
2020-05-03 12:40:52,660 - util.py[DEBUG]: dmi data /sys/class/dmi/id/product_serial returned VMware-56 4d d2 8e e5 50 c4 9e-e1 d9 14 6f 11 1a 1f a9
2020-05-03 12:40:52,660 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/user-data (quiet=False)
2020-05-03 12:40:52,660 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/seed/nocloud/user-data
2020-05-03 12:40:52,660 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/meta-data (quiet=False)
2020-05-03 12:40:52,660 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/seed/nocloud/meta-data
2020-05-03 12:40:52,660 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/vendor-data (quiet=False)
2020-05-03 12:40:52,660 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/network-config (quiet=False)
2020-05-03 12:40:52,660 - DataSourceNoCloud.py[DEBUG]: Using seeded data from /var/lib/cloud/seed/nocloud
2020-05-03 12:40:52,661 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,661 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:52,687 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-05-03 12:40:52,687 - util.py[DEBUG]: Read 378 bytes from /etc/os-release
2020-05-03 12:40:52,688 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-05-03 12:40:52,692 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-05-03 12:40:52,694 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-05-03 12:40:52,699 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-05-03 12:40:52,703 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=CIDATA', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-05-03 12:40:52,707 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2020-05-03 12:40:52,711 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2020-05-03 12:40:52,711 - util.py[DEBUG]: Read 250 bytes from /etc/hosts
2020-05-03 12:40:52,712 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data-sensitive.json (via temporary file /run/cloud-init/tmp7mtyeqf6) - w: [600] 4846 bytes/chars
2020-05-03 12:40:52,712 - atomic_helper.py[DEBUG]: Atomically writing to file /run/cloud-init/instance-data.json (via temporary file /run/cloud-init/tmp4i76ae9g) - w: [644] 1400 bytes/chars
2020-05-03 12:40:52,713 - handlers.py[DEBUG]: finish: init-local/search-NoCloud: SUCCESS: found local data from DataSourceNoCloud
2020-05-03 12:40:52,713 - stages.py[INFO]: Loaded datasource DataSourceNoCloud - DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud][dsmode=net]
2020-05-03 12:40:52,713 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-05-03 12:40:52,713 - util.py[DEBUG]: Read 4017 bytes from /etc/cloud/cloud.cfg
2020-05-03 12:40:52,713 - util.py[DEBUG]: Attempting to load yaml from string of length 4017 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,722 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-05-03 12:40:52,722 - util.py[DEBUG]: Read 285 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-05-03 12:40:52,722 - util.py[DEBUG]: Attempting to load yaml from string of length 285 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,723 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-05-03 12:40:52,723 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-05-03 12:40:52,723 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,725 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-05-03 12:40:52,726 - util.py[DEBUG]: Read 40 bytes from /run/cloud-init/cloud.cfg
2020-05-03 12:40:52,726 - util.py[DEBUG]: Attempting to load yaml from string of length 40 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,726 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,726 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:52,726 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-05-03 12:40:52,726 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/nocloud'
2020-05-03 12:40:52,727 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/nocloud/datasource (quiet=False)
2020-05-03 12:40:52,727 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/datasource - wb: [644] 84 bytes
2020-05-03 12:40:52,727 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 84 bytes
2020-05-03 12:40:52,728 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-05-03 12:40:52,728 - stages.py[DEBUG]: previous iid found to be NO_PREVIOUS_INSTANCE_ID
2020-05-03 12:40:52,728 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 8 bytes
2020-05-03 12:40:52,728 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 8 bytes
2020-05-03 12:40:52,728 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 24 bytes
2020-05-03 12:40:52,729 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 5637 bytes
2020-05-03 12:40:52,729 - main.py[DEBUG]: [local] init will now be targeting instance id: nocloud. new=True
2020-05-03 12:40:52,729 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-05-03 12:40:52,729 - util.py[DEBUG]: Read 4017 bytes from /etc/cloud/cloud.cfg
2020-05-03 12:40:52,729 - util.py[DEBUG]: Attempting to load yaml from string of length 4017 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,738 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-05-03 12:40:52,738 - util.py[DEBUG]: Read 285 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-05-03 12:40:52,738 - util.py[DEBUG]: Attempting to load yaml from string of length 285 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,739 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-05-03 12:40:52,739 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-05-03 12:40:52,739 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,742 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-05-03 12:40:52,742 - util.py[DEBUG]: Read 40 bytes from /run/cloud-init/cloud.cfg
2020-05-03 12:40:52,742 - util.py[DEBUG]: Attempting to load yaml from string of length 40 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,742 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:52,742 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:52,743 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/ens192/address (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/ens192/address
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/lo/addr_assign_type (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/lo/addr_assign_type
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/lo/uevent (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Read 23 bytes from /sys/class/net/lo/uevent
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/lo/device/device (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/ens192/addr_assign_type (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/ens192/addr_assign_type
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/ens192/uevent (quiet=False)
2020-05-03 12:40:52,744 - util.py[DEBUG]: Read 27 bytes from /sys/class/net/ens192/uevent
2020-05-03 12:40:52,744 - util.py[DEBUG]: Reading from /sys/class/net/ens192/address (quiet=False)
2020-05-03 12:40:52,745 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/ens192/address
2020-05-03 12:40:52,745 - util.py[DEBUG]: Reading from /sys/class/net/ens192/device/device (quiet=False)
2020-05-03 12:40:52,745 - util.py[DEBUG]: Read 7 bytes from /sys/class/net/ens192/device/device
2020-05-03 12:40:52,745 - util.py[DEBUG]: Reading from /sys/class/net/lo/type (quiet=False)
2020-05-03 12:40:52,745 - util.py[DEBUG]: Read 4 bytes from /sys/class/net/lo/type
2020-05-03 12:40:52,745 - util.py[DEBUG]: Reading from /sys/class/net/ens192/type (quiet=False)
2020-05-03 12:40:52,745 - util.py[DEBUG]: Read 2 bytes from /sys/class/net/ens192/type
2020-05-03 12:40:52,745 - __init__.py[DEBUG]: net: all expected physical devices present
2020-05-03 12:40:52,745 - stages.py[DEBUG]: applying net config names for {'version': 2, 'ethernets': {'zz-all-en': {'match': {'name': 'en*'}, 'dhcp4': True}, 'zz-all-eth': {'match': {'name': 'eth*'}, 'dhcp4': True}}}
2020-05-03 12:40:52,745 - __init__.py[DEBUG]: no interfaces to rename
2020-05-03 12:40:52,745 - stages.py[INFO]: Applying network configuration from system_cfg bringup=False: {'version': 2, 'ethernets': {'zz-all-en': {'match': {'name': 'en*'}, 'dhcp4': True}, 'zz-all-eth': {'match': {'name': 'eth*'}, 'dhcp4': True}}}
2020-05-03 12:40:52,748 - __init__.py[DEBUG]: Selected renderer 'netplan' from priority list: None
2020-05-03 12:40:52,748 - network_state.py[DEBUG]: NetworkState Version2: missing "macaddress" info in config entry: zz-all-en: {'match': {'name': 'en*'}, 'dhcp4': True}
2020-05-03 12:40:52,748 - network_state.py[DEBUG]: v2(ethernets) -> v1(physical):
{'type': 'physical', 'name': 'zz-all-en', 'mac_address': None, 'match': {'name': 'en*'}, 'subnets': [{'type': 'dhcp4'}]}
2020-05-03 12:40:52,750 - network_state.py[DEBUG]: NetworkState Version2: missing "macaddress" info in config entry: zz-all-eth: {'match': {'name': 'eth*'}, 'dhcp4': True}
2020-05-03 12:40:52,750 - network_state.py[DEBUG]: v2(ethernets) -> v1(physical):
{'type': 'physical', 'name': 'zz-all-eth', 'mac_address': None, 'match': {'name': 'eth*'}, 'subnets': [{'type': 'dhcp4'}]}
2020-05-03 12:40:52,751 - network_state.py[DEBUG]: v2_common: handling config:
{'zz-all-en': {'match': {'name': 'en*'}, 'dhcp4': True}, 'zz-all-eth': {'match': {'name': 'eth*'}, 'dhcp4': True}}
2020-05-03 12:40:52,752 - netplan.py[DEBUG]: V2 to V2 passthrough
2020-05-03 12:40:52,752 - util.py[DEBUG]: Writing to /etc/netplan/50-cloud-init.yaml - wb: [644] 529 bytes
2020-05-03 12:40:52,753 - util.py[DEBUG]: Running command ['netplan', 'generate'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:52,840 - util.py[DEBUG]: Running command ['udevadm', 'test-builtin', 'net_setup_link', '/sys/class/net/lo'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:52,846 - util.py[DEBUG]: Running command ['udevadm', 'test-builtin', 'net_setup_link', '/sys/class/net/ens192'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:52,850 - main.py[DEBUG]: [local] Exiting. datasource DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud][dsmode=net] not in local mode.
2020-05-03 12:40:52,851 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmprf12stfs) - w: [644] 536 bytes/chars
2020-05-03 12:40:52,851 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-05-03 12:40:52,851 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2020-05-03 12:40:52,851 - util.py[DEBUG]: cloud-init mode 'init' took 0.266 seconds (0.26)
2020-05-03 12:40:52,851 - handlers.py[DEBUG]: finish: init-local: SUCCESS: searching for local datasources
2020-05-03 12:40:53,917 - util.py[DEBUG]: Cloud-init v. 20.1-10-g71af48df-0ubuntu5 running 'init' at Sun, 03 May 2020 12:40:53 +0000. Up 17.06 seconds.
2020-05-03 12:40:53,918 - main.py[DEBUG]: No kernel command line url found.
2020-05-03 12:40:53,918 - main.py[DEBUG]: Closing stdin.
2020-05-03 12:40:53,919 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [644] 0 bytes
2020-05-03 12:40:53,919 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 104:4
2020-05-03 12:40:53,926 - util.py[DEBUG]: Running command ['ip', 'addr', 'show'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:53,988 - util.py[DEBUG]: Running command ['ip', '-o', 'route', 'list'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:53,991 - util.py[DEBUG]: Running command ['ip', '--oneline', '-6', 'route', 'list', 'table', 'all'] with allowed return codes [0, 1] (shell=False, capture=True)
2020-05-03 12:40:53,993 - 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-05-03 12:40:53,993 - main.py[DEBUG]: Execution continuing, no previous run detected that would allow us to stop early.
2020-05-03 12:40:53,994 - handlers.py[DEBUG]: start: init-network/check-cache: attempting to read from cache [trust]
2020-05-03 12:40:53,994 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2020-05-03 12:40:53,994 - util.py[DEBUG]: Read 5637 bytes from /var/lib/cloud/instance/obj.pkl
2020-05-03 12:40:53,996 - util.py[DEBUG]: Reading from /run/cloud-init/.instance-id (quiet=False)
2020-05-03 12:40:53,996 - util.py[DEBUG]: Read 8 bytes from /run/cloud-init/.instance-id
2020-05-03 12:40:53,996 - stages.py[DEBUG]: restored from cache with run check: DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud][dsmode=net]
2020-05-03 12:40:53,996 - handlers.py[DEBUG]: finish: init-network/check-cache: SUCCESS: restored from cache with run check: DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud][dsmode=net]
2020-05-03 12:40:53,996 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-05-03 12:40:53,996 - util.py[DEBUG]: Read 4017 bytes from /etc/cloud/cloud.cfg
2020-05-03 12:40:53,996 - util.py[DEBUG]: Attempting to load yaml from string of length 4017 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,005 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-05-03 12:40:54,005 - util.py[DEBUG]: Read 285 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-05-03 12:40:54,005 - util.py[DEBUG]: Attempting to load yaml from string of length 285 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,006 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-05-03 12:40:54,006 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-05-03 12:40:54,006 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,009 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-05-03 12:40:54,009 - util.py[DEBUG]: Read 40 bytes from /run/cloud-init/cloud.cfg
2020-05-03 12:40:54,009 - util.py[DEBUG]: Attempting to load yaml from string of length 40 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,009 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,009 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:54,009 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2020-05-03 12:40:54,010 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/nocloud'
2020-05-03 12:40:54,010 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/nocloud/datasource (quiet=False)
2020-05-03 12:40:54,010 - util.py[DEBUG]: Read 84 bytes from /var/lib/cloud/instances/nocloud/datasource
2020-05-03 12:40:54,010 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/datasource - wb: [644] 84 bytes
2020-05-03 12:40:54,010 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [644] 84 bytes
2020-05-03 12:40:54,010 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2020-05-03 12:40:54,011 - util.py[DEBUG]: Read 8 bytes from /var/lib/cloud/data/instance-id
2020-05-03 12:40:54,011 - stages.py[DEBUG]: previous iid found to be nocloud
2020-05-03 12:40:54,011 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [644] 8 bytes
2020-05-03 12:40:54,011 - util.py[DEBUG]: Writing to /run/cloud-init/.instance-id - wb: [644] 8 bytes
2020-05-03 12:40:54,011 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [644] 8 bytes
2020-05-03 12:40:54,012 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 5689 bytes
2020-05-03 12:40:54,012 - main.py[DEBUG]: [net] init will now be targeting instance id: nocloud. new=False
2020-05-03 12:40:54,012 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-05-03 12:40:54,012 - util.py[DEBUG]: Read 4017 bytes from /etc/cloud/cloud.cfg
2020-05-03 12:40:54,012 - util.py[DEBUG]: Attempting to load yaml from string of length 4017 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,022 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-05-03 12:40:54,022 - util.py[DEBUG]: Read 285 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-05-03 12:40:54,022 - util.py[DEBUG]: Attempting to load yaml from string of length 285 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,023 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-05-03 12:40:54,023 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-05-03 12:40:54,023 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,026 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-05-03 12:40:54,026 - util.py[DEBUG]: Read 40 bytes from /run/cloud-init/cloud.cfg
2020-05-03 12:40:54,026 - util.py[DEBUG]: Attempting to load yaml from string of length 40 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,026 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,026 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:54,042 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-05-03 12:40:54,042 - util.py[DEBUG]: Read 378 bytes from /etc/os-release
2020-05-03 12:40:54,043 - util.py[DEBUG]: Reading from /sys/class/net/lo/address (quiet=False)
2020-05-03 12:40:54,043 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/lo/address
2020-05-03 12:40:54,043 - util.py[DEBUG]: Reading from /sys/class/net/ens192/address (quiet=False)
2020-05-03 12:40:54,043 - util.py[DEBUG]: Read 18 bytes from /sys/class/net/ens192/address
2020-05-03 12:40:54,043 - __init__.py[DEBUG]: Datasource DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud][dsmode=net] not updated for events: System boot
2020-05-03 12:40:54,043 - stages.py[DEBUG]: No network config applied. Neither a new instance nor datasource network update on 'System boot' event
2020-05-03 12:40:54,043 - stages.py[DEBUG]: applying net config names for {'version': 2, 'ethernets': {'zz-all-en': {'match': {'name': 'en*'}, 'dhcp4': True}, 'zz-all-eth': {'match': {'name': 'eth*'}, 'dhcp4': True}}}
2020-05-03 12:40:54,043 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2020-05-03 12:40:54,044 - __init__.py[DEBUG]: no interfaces to rename
2020-05-03 12:40:54,044 - handlers.py[DEBUG]: start: init-network/setup-datasource: setting up datasource
2020-05-03 12:40:54,044 - handlers.py[DEBUG]: finish: init-network/setup-datasource: SUCCESS: setting up datasource
2020-05-03 12:40:54,044 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt - wb: [600] 0 bytes
2020-05-03 12:40:54,049 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt.i - wb: [600] 308 bytes
2020-05-03 12:40:54,049 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data.txt - wb: [600] 0 bytes
2020-05-03 12:40:54,050 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/vendor-data.txt.i - wb: [600] 308 bytes
2020-05-03 12:40:54,051 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/consume_data - wb: [644] 24 bytes
2020-05-03 12:40:54,051 - helpers.py[DEBUG]: Running consume_data using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/consume_data'>)
2020-05-03 12:40:54,051 - handlers.py[DEBUG]: start: init-network/consume-user-data: reading and applying user-data
2020-05-03 12:40:54,051 - stages.py[DEBUG]: Added default handler for {'text/cloud-config-jsonp', 'text/cloud-config'} from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2020-05-03 12:40:54,051 - stages.py[DEBUG]: Added default handler for {'text/x-shellscript'} from ShellScriptPartHandler: [['text/x-shellscript']]
2020-05-03 12:40:54,051 - stages.py[DEBUG]: Added default handler for {'text/cloud-boothook'} from BootHookPartHandler: [['text/cloud-boothook']]
2020-05-03 12:40:54,051 - stages.py[DEBUG]: Added default handler for {'text/upstart-job'} from UpstartJobPartHandler: [['text/upstart-job']]
2020-05-03 12:40:54,051 - stages.py[DEBUG]: Added default handler for {'text/jinja2'} from JinjaTemplatePartHandler: [['text/jinja2']]
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__begin__, None, 3) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: {'MIME-Version': '1.0', 'Content-Type': 'text/x-not-multipart', 'Content-Disposition': 'attachment; filename="part-001"'}
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Empty payload of type text/x-not-multipart
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2020-05-03 12:40:54,052 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/cloud-config.txt - wb: [600] 0 bytes
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2020-05-03 12:40:54,052 - __init__.py[DEBUG]: Calling handler JinjaTemplatePartHandler: [['text/jinja2']] (__end__, None, 3) with frequency once-per-instance
2020-05-03 12:40:54,052 - handlers.py[DEBUG]: finish: init-network/consume-user-data: SUCCESS: reading and applying user-data
2020-05-03 12:40:54,052 - handlers.py[DEBUG]: start: init-network/consume-vendor-data: reading and applying vendor-data
2020-05-03 12:40:54,053 - stages.py[DEBUG]: no vendordata from datasource
2020-05-03 12:40:54,053 - handlers.py[DEBUG]: finish: init-network/consume-vendor-data: SUCCESS: reading and applying vendor-data
2020-05-03 12:40:54,053 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2020-05-03 12:40:54,053 - util.py[DEBUG]: Read 4017 bytes from /etc/cloud/cloud.cfg
2020-05-03 12:40:54,053 - util.py[DEBUG]: Attempting to load yaml from string of length 4017 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,061 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2020-05-03 12:40:54,061 - util.py[DEBUG]: Read 285 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2020-05-03 12:40:54,061 - util.py[DEBUG]: Attempting to load yaml from string of length 285 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,063 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2020-05-03 12:40:54,063 - util.py[DEBUG]: Read 2057 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2020-05-03 12:40:54,063 - util.py[DEBUG]: Attempting to load yaml from string of length 2057 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,065 - util.py[DEBUG]: Reading from /run/cloud-init/cloud.cfg (quiet=False)
2020-05-03 12:40:54,065 - util.py[DEBUG]: Read 40 bytes from /run/cloud-init/cloud.cfg
2020-05-03 12:40:54,065 - util.py[DEBUG]: Attempting to load yaml from string of length 40 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,065 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,066 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:54,066 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-05-03 12:40:54,066 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-05-03 12:40:54,066 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,066 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:54,066 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2020-05-03 12:40:54,066 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2020-05-03 12:40:54,066 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<class 'dict'>,)
2020-05-03 12:40:54,066 - util.py[DEBUG]: loaded blob returned None, returning default.
2020-05-03 12:40:54,072 - handlers.py[DEBUG]: start: init-network/activate-datasource: activating datasource
2020-05-03 12:40:54,072 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [400] 7251 bytes
2020-05-03 12:40:54,072 - handlers.py[DEBUG]: finish: init-network/activate-datasource: SUCCESS: activating datasource
2020-05-03 12:40:54,073 - main.py[DEBUG]: no di_report found in config.
2020-05-03 12:40:54,098 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2020-05-03 12:40:54,098 - stages.py[DEBUG]: Running module bootcmd (<module 'cloudinit.config.cc_bootcmd' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_bootcmd.py'>) with frequency always
2020-05-03 12:40:54,098 - handlers.py[DEBUG]: start: init-network/config-bootcmd: running config-bootcmd with frequency always
2020-05-03 12:40:54,099 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x7f6f2ea38e80>)
2020-05-03 12:40:54,099 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2020-05-03 12:40:54,099 - handlers.py[DEBUG]: finish: init-network/config-bootcmd: SUCCESS: config-bootcmd ran successfully
2020-05-03 12:40:54,099 - stages.py[DEBUG]: Running module write-files (<module 'cloudinit.config.cc_write_files' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_write_files.py'>) with frequency once-per-instance
2020-05-03 12:40:54,099 - handlers.py[DEBUG]: start: init-network/config-write-files: running config-write-files with frequency once-per-instance
2020-05-03 12:40:54,099 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_write_files - wb: [644] 25 bytes
2020-05-03 12:40:54,099 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_write_files'>)
2020-05-03 12:40:54,099 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2020-05-03 12:40:54,099 - handlers.py[DEBUG]: finish: init-network/config-write-files: SUCCESS: config-write-files ran successfully
2020-05-03 12:40:54,099 - stages.py[DEBUG]: Running module ca-certs (<module 'cloudinit.config.cc_ca_certs' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ca_certs.py'>) with frequency once-per-instance
2020-05-03 12:40:54,099 - handlers.py[DEBUG]: start: init-network/config-ca-certs: running config-ca-certs with frequency once-per-instance
2020-05-03 12:40:54,099 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ca_certs - wb: [644] 25 bytes
2020-05-03 12:40:54,100 - helpers.py[DEBUG]: Running config-ca-certs using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ca_certs'>)
2020-05-03 12:40:54,100 - cc_ca_certs.py[DEBUG]: Skipping module named ca-certs, no 'ca-certs' key in configuration
2020-05-03 12:40:54,100 - handlers.py[DEBUG]: finish: init-network/config-ca-certs: SUCCESS: config-ca-certs ran successfully
2020-05-03 12:40:54,100 - stages.py[DEBUG]: Running module rsyslog (<module 'cloudinit.config.cc_rsyslog' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_rsyslog.py'>) with frequency once-per-instance
2020-05-03 12:40:54,100 - handlers.py[DEBUG]: start: init-network/config-rsyslog: running config-rsyslog with frequency once-per-instance
2020-05-03 12:40:54,100 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_rsyslog - wb: [644] 25 bytes
2020-05-03 12:40:54,100 - helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_rsyslog'>)
2020-05-03 12:40:54,100 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
2020-05-03 12:40:54,100 - handlers.py[DEBUG]: finish: init-network/config-rsyslog: SUCCESS: config-rsyslog ran successfully
2020-05-03 12:40:54,100 - stages.py[DEBUG]: Running module users-groups (<module 'cloudinit.config.cc_users_groups' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_users_groups.py'>) with frequency once-per-instance
2020-05-03 12:40:54,101 - handlers.py[DEBUG]: start: init-network/config-users-groups: running config-users-groups with frequency once-per-instance
2020-05-03 12:40:54,101 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_users_groups - wb: [644] 25 bytes
2020-05-03 12:40:54,104 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_users_groups'>)
2020-05-03 12:40:54,105 - util.py[DEBUG]: Reading from /etc/os-release (quiet=True)
2020-05-03 12:40:54,105 - util.py[DEBUG]: Read 378 bytes from /etc/os-release
2020-05-03 12:40:54,106 - util.py[DEBUG]: Reading from /etc/system-image/channel.ini (quiet=True)
2020-05-03 12:40:54,106 - util.py[DEBUG]: Read 0 bytes from /etc/system-image/channel.ini
2020-05-03 12:40:54,106 - util.py[DEBUG]: Reading from /etc/os-release (quiet=True)
2020-05-03 12:40:54,107 - util.py[DEBUG]: Read 378 bytes from /etc/os-release
2020-05-03 12:40:54,107 - util.py[DEBUG]: Reading from /etc/system-image/channel.ini (quiet=True)
2020-05-03 12:40:54,107 - util.py[DEBUG]: Read 0 bytes from /etc/system-image/channel.ini
2020-05-03 12:40:54,107 - util.py[DEBUG]: Running command ['groupadd', 'netdev'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:54,112 - __init__.py[INFO]: Created new group netdev
2020-05-03 12:40:54,112 - __init__.py[DEBUG]: created group 'netdev' for user 'installer'
2020-05-03 12:40:54,112 - __init__.py[DEBUG]: Adding user installer
2020-05-03 12:40:54,112 - util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['useradd', 'installer', '--comment', 'Ubuntu', '--groups', 'adm,audio,cdrom,dialout,dip,floppy,lxd,netdev,plugdev,sudo,video', '--shell', '/usr/bin/subiquity-shell', '-m']
2020-05-03 12:40:54,123 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False)
2020-05-03 12:40:54,126 - util.py[DEBUG]: Read 755 bytes from /etc/sudoers
2020-05-03 12:40:54,127 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - wb: [440] 150 bytes
2020-05-03 12:40:54,127 - handlers.py[DEBUG]: finish: init-network/config-users-groups: SUCCESS: config-users-groups ran successfully
2020-05-03 12:40:54,127 - stages.py[DEBUG]: Running module ssh (<module 'cloudinit.config.cc_ssh' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh.py'>) with frequency once-per-instance
2020-05-03 12:40:54,127 - handlers.py[DEBUG]: start: init-network/config-ssh: running config-ssh with frequency once-per-instance
2020-05-03 12:40:54,127 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh - wb: [644] 25 bytes
2020-05-03 12:40:54,128 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh'>)
2020-05-03 12:40:54,128 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key
2020-05-03 12:40:54,128 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ecdsa_key.pub
2020-05-03 12:40:54,128 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key
2020-05-03 12:40:54,128 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_ed25519_key.pub
2020-05-03 12:40:54,128 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key
2020-05-03 12:40:54,128 - util.py[DEBUG]: Attempting to remove /etc/ssh/ssh_host_rsa_key.pub
2020-05-03 12:40:54,129 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:54,212 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'dsa', '-N', '', '-f', '/etc/ssh/ssh_host_dsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:54,250 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ecdsa', '-N', '', '-f', '/etc/ssh/ssh_host_ecdsa_key'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:54,254 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ed25519', '-N', '', '-f', '/etc/ssh/ssh_host_ed25519_key'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:40:54,259 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ed25519_key.pub (quiet=False)
2020-05-03 12:40:54,259 - util.py[DEBUG]: Read 100 bytes from /etc/ssh/ssh_host_ed25519_key.pub
2020-05-03 12:40:54,259 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_ecdsa_key.pub (quiet=False)
2020-05-03 12:40:54,260 - util.py[DEBUG]: Read 180 bytes from /etc/ssh/ssh_host_ecdsa_key.pub
2020-05-03 12:40:54,260 - util.py[DEBUG]: Reading from /etc/ssh/ssh_host_rsa_key.pub (quiet=False)
2020-05-03 12:40:54,260 - util.py[DEBUG]: Read 572 bytes from /etc/ssh/ssh_host_rsa_key.pub
2020-05-03 12:40:54,260 - util.py[DEBUG]: Changing the ownership of /home/installer/.ssh to 1000:1001
2020-05-03 12:40:54,260 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-05-03 12:40:54,263 - util.py[DEBUG]: Read 3289 bytes from /etc/ssh/sshd_config
2020-05-03 12:40:54,263 - util.py[DEBUG]: Writing to /home/installer/.ssh/authorized_keys - wb: [600] 0 bytes
2020-05-03 12:40:54,263 - util.py[DEBUG]: Changing the ownership of /home/installer/.ssh/authorized_keys to 1000:1001
2020-05-03 12:40:54,264 - util.py[DEBUG]: Changing the ownership of /root/.ssh to 0:0
2020-05-03 12:40:54,264 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-05-03 12:40:54,264 - util.py[DEBUG]: Read 3289 bytes from /etc/ssh/sshd_config
2020-05-03 12:40:54,264 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [600] 0 bytes
2020-05-03 12:40:54,264 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2020-05-03 12:40:54,265 - handlers.py[DEBUG]: finish: init-network/config-ssh: SUCCESS: config-ssh ran successfully
2020-05-03 12:40:54,265 - main.py[DEBUG]: Ran 6 modules with 0 failures
2020-05-03 12:40:54,265 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmp7ka822hu) - w: [644] 563 bytes/chars
2020-05-03 12:40:54,265 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-05-03 12:40:54,265 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2020-05-03 12:40:54,265 - util.py[DEBUG]: cloud-init mode 'init' took 0.412 seconds (0.41)
2020-05-03 12:40:54,265 - handlers.py[DEBUG]: finish: init-network: SUCCESS: searching for network datasources
2020-05-03 12:41:11,770 - util.py[DEBUG]: Cloud-init v. 20.1-10-g71af48df-0ubuntu5 running 'modules:config' at Sun, 03 May 2020 12:41:11 +0000. Up 34.81 seconds.
2020-05-03 12:41:11,790 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2020-05-03 12:41:11,793 - stages.py[DEBUG]: Running module ssh-import-id (<module 'cloudinit.config.cc_ssh_import_id' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_import_id.py'>) with frequency once-per-instance
2020-05-03 12:41:11,793 - handlers.py[DEBUG]: start: modules-config/config-ssh-import-id: running config-ssh-import-id with frequency once-per-instance
2020-05-03 12:41:11,794 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh_import_id - wb: [644] 25 bytes
2020-05-03 12:41:11,794 - helpers.py[DEBUG]: Running config-ssh-import-id using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh_import_id'>)
2020-05-03 12:41:11,794 - handlers.py[DEBUG]: finish: modules-config/config-ssh-import-id: SUCCESS: config-ssh-import-id ran successfully
2020-05-03 12:41:11,794 - stages.py[DEBUG]: Running module set-passwords (<module 'cloudinit.config.cc_set_passwords' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_set_passwords.py'>) with frequency once-per-instance
2020-05-03 12:41:11,794 - handlers.py[DEBUG]: start: modules-config/config-set-passwords: running config-set-passwords with frequency once-per-instance
2020-05-03 12:41:11,794 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_set_passwords - wb: [644] 24 bytes
2020-05-03 12:41:11,795 - helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_set_passwords'>)
2020-05-03 12:41:11,795 - cc_set_passwords.py[DEBUG]: Handling input for chpasswd as list.
2020-05-03 12:41:11,797 - cc_set_passwords.py[DEBUG]: Changing password for ['installer']:
2020-05-03 12:41:11,863 - util.py[DEBUG]: Reading from /etc/os-release (quiet=False)
2020-05-03 12:41:11,863 - util.py[DEBUG]: Read 378 bytes from /etc/os-release
2020-05-03 12:41:11,864 - util.py[DEBUG]: Running command ['chpasswd'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:41:11,962 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-05-03 12:41:11,963 - util.py[DEBUG]: Read 3289 bytes from /etc/ssh/sshd_config
2020-05-03 12:41:11,963 - ssh_util.py[DEBUG]: line 124: option PasswordAuthentication added with yes
2020-05-03 12:41:11,963 - util.py[DEBUG]: Writing to /etc/ssh/sshd_config - wb: [644] 3316 bytes
2020-05-03 12:41:11,963 - util.py[DEBUG]: Running command ['service', 'ssh', 'restart'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:41:12,154 - cc_set_passwords.py[DEBUG]: Restarted the SSH daemon.
2020-05-03 12:41:12,154 - handlers.py[DEBUG]: finish: modules-config/config-set-passwords: SUCCESS: config-set-passwords ran successfully
2020-05-03 12:41:12,154 - stages.py[DEBUG]: Running module timezone (<module 'cloudinit.config.cc_timezone' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_timezone.py'>) with frequency once-per-instance
2020-05-03 12:41:12,155 - handlers.py[DEBUG]: start: modules-config/config-timezone: running config-timezone with frequency once-per-instance
2020-05-03 12:41:12,155 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_timezone - wb: [644] 24 bytes
2020-05-03 12:41:12,155 - helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_timezone'>)
2020-05-03 12:41:12,155 - cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified
2020-05-03 12:41:12,155 - handlers.py[DEBUG]: finish: modules-config/config-timezone: SUCCESS: config-timezone ran successfully
2020-05-03 12:41:12,155 - stages.py[DEBUG]: Running module disable-ec2-metadata (<module 'cloudinit.config.cc_disable_ec2_metadata' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_disable_ec2_metadata.py'>) with frequency always
2020-05-03 12:41:12,156 - handlers.py[DEBUG]: start: modules-config/config-disable-ec2-metadata: running config-disable-ec2-metadata with frequency always
2020-05-03 12:41:12,156 - helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock (<cloudinit.helpers.DummyLock object at 0x7f5459c23820>)
2020-05-03 12:41:12,156 - cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled
2020-05-03 12:41:12,156 - handlers.py[DEBUG]: finish: modules-config/config-disable-ec2-metadata: SUCCESS: config-disable-ec2-metadata ran successfully
2020-05-03 12:41:12,156 - stages.py[DEBUG]: Running module runcmd (<module 'cloudinit.config.cc_runcmd' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_runcmd.py'>) with frequency once-per-instance
2020-05-03 12:41:12,156 - handlers.py[DEBUG]: start: modules-config/config-runcmd: running config-runcmd with frequency once-per-instance
2020-05-03 12:41:12,156 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_runcmd - wb: [644] 25 bytes
2020-05-03 12:41:12,156 - helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_runcmd'>)
2020-05-03 12:41:12,156 - cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration
2020-05-03 12:41:12,156 - handlers.py[DEBUG]: finish: modules-config/config-runcmd: SUCCESS: config-runcmd ran successfully
2020-05-03 12:41:12,156 - main.py[DEBUG]: Ran 5 modules with 0 failures
2020-05-03 12:41:12,157 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpm15d0ye6) - w: [644] 591 bytes/chars
2020-05-03 12:41:12,157 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-05-03 12:41:12,157 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2020-05-03 12:41:12,157 - util.py[DEBUG]: cloud-init mode 'modules' took 0.541 seconds (0.54)
2020-05-03 12:41:12,157 - handlers.py[DEBUG]: finish: modules-config: SUCCESS: running modules for config
2020-05-03 12:41:13,014 - util.py[DEBUG]: Cloud-init v. 20.1-10-g71af48df-0ubuntu5 running 'modules:final' at Sun, 03 May 2020 12:41:12 +0000. Up 36.10 seconds.
2020-05-03 12:41:13,038 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2020-05-03 12:41:13,038 - stages.py[DEBUG]: Running module scripts-per-once (<module 'cloudinit.config.cc_scripts_per_once' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_per_once.py'>) with frequency once
2020-05-03 12:41:13,038 - handlers.py[DEBUG]: start: modules-final/config-scripts-per-once: running config-scripts-per-once with frequency once
2020-05-03 12:41:13,039 - util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [644] 25 bytes
2020-05-03 12:41:13,039 - helpers.py[DEBUG]: Running config-scripts-per-once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>)
2020-05-03 12:41:13,039 - handlers.py[DEBUG]: finish: modules-final/config-scripts-per-once: SUCCESS: config-scripts-per-once ran successfully
2020-05-03 12:41:13,039 - stages.py[DEBUG]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py'>) with frequency once-per-instance
2020-05-03 12:41:13,039 - handlers.py[DEBUG]: start: modules-final/config-scripts-user: running config-scripts-user with frequency once-per-instance
2020-05-03 12:41:13,039 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_user - wb: [644] 25 bytes
2020-05-03 12:41:13,039 - helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_user'>)
2020-05-03 12:41:13,040 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: SUCCESS: config-scripts-user ran successfully
2020-05-03 12:41:13,040 - stages.py[DEBUG]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) with frequency once-per-instance
2020-05-03 12:41:13,040 - handlers.py[DEBUG]: start: modules-final/config-ssh-authkey-fingerprints: running config-ssh-authkey-fingerprints with frequency once-per-instance
2020-05-03 12:41:13,040 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints - wb: [644] 25 bytes
2020-05-03 12:41:13,040 - helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints'>)
2020-05-03 12:41:13,040 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2020-05-03 12:41:13,040 - util.py[DEBUG]: Read 3316 bytes from /etc/ssh/sshd_config
2020-05-03 12:41:13,045 - util.py[DEBUG]: Reading from /home/installer/.ssh/authorized_keys (quiet=False)
2020-05-03 12:41:13,045 - util.py[DEBUG]: Read 0 bytes from /home/installer/.ssh/authorized_keys
2020-05-03 12:41:13,045 - handlers.py[DEBUG]: finish: modules-final/config-ssh-authkey-fingerprints: SUCCESS: config-ssh-authkey-fingerprints ran successfully
2020-05-03 12:41:13,045 - stages.py[DEBUG]: Running module keys-to-console (<module 'cloudinit.config.cc_keys_to_console' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_keys_to_console.py'>) with frequency once-per-instance
2020-05-03 12:41:13,045 - handlers.py[DEBUG]: start: modules-final/config-keys-to-console: running config-keys-to-console with frequency once-per-instance
2020-05-03 12:41:13,045 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_keys_to_console - wb: [644] 24 bytes
2020-05-03 12:41:13,046 - helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_keys_to_console'>)
2020-05-03 12:41:13,046 - util.py[DEBUG]: Running command ['/usr/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True)
2020-05-03 12:41:13,135 - handlers.py[DEBUG]: finish: modules-final/config-keys-to-console: SUCCESS: config-keys-to-console ran successfully
2020-05-03 12:41:13,135 - stages.py[DEBUG]: Running module phone-home (<module 'cloudinit.config.cc_phone_home' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_phone_home.py'>) with frequency once-per-instance
2020-05-03 12:41:13,135 - handlers.py[DEBUG]: start: modules-final/config-phone-home: running config-phone-home with frequency once-per-instance
2020-05-03 12:41:13,135 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_phone_home - wb: [644] 25 bytes
2020-05-03 12:41:13,136 - helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_phone_home'>)
2020-05-03 12:41:13,136 - cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
2020-05-03 12:41:13,136 - handlers.py[DEBUG]: finish: modules-final/config-phone-home: SUCCESS: config-phone-home ran successfully
2020-05-03 12:41:13,136 - stages.py[DEBUG]: Running module final-message (<module 'cloudinit.config.cc_final_message' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_final_message.py'>) with frequency always
2020-05-03 12:41:13,136 - handlers.py[DEBUG]: start: modules-final/config-final-message: running config-final-message with frequency always
2020-05-03 12:41:13,136 - helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x7f020955d070>)
2020-05-03 12:41:13,136 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-05-03 12:41:13,136 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2020-05-03 12:41:13,143 - util.py[DEBUG]: Cloud-init v. 20.1-10-g71af48df-0ubuntu5 finished at Sun, 03 May 2020 12:41:13 +0000. Datasource DataSourceNoCloud [seed=/var/lib/cloud/seed/nocloud][dsmode=net].  Up 36.32 seconds


Welcome to Ubuntu Server Installer!

Above you will find SSH host keys and a random password set for the `installer` user. You can use these credentials to ssh-in and complete the installation. If you provided SSH keys in the cloud-init datasource, they were also provisioned to the installer user.

If you have access to the graphical console, like TTY1 or HMC ASCII terminal you can complete the installation there too.
2020-05-03 12:41:13,143 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [644] 72 bytes
2020-05-03 12:41:13,143 - handlers.py[DEBUG]: finish: modules-final/config-final-message: SUCCESS: config-final-message ran successfully
2020-05-03 12:41:13,143 - main.py[DEBUG]: Ran 6 modules with 0 failures
2020-05-03 12:41:13,144 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/status.json (via temporary file /var/lib/cloud/data/tmpdrp0drog) - w: [644] 618 bytes/chars
2020-05-03 12:41:13,144 - atomic_helper.py[DEBUG]: Atomically writing to file /var/lib/cloud/data/result.json (via temporary file /var/lib/cloud/data/tmp9gjl01qr) - w: [644] 115 bytes/chars
2020-05-03 12:41:13,144 - util.py[DEBUG]: Creating symbolic link from '/run/cloud-init/result.json' => '../../var/lib/cloud/data/result.json'
2020-05-03 12:41:13,144 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2020-05-03 12:41:13,144 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2020-05-03 12:41:13,144 - util.py[DEBUG]: cloud-init mode 'modules' took 0.232 seconds (0.23)
2020-05-03 12:41:13,144 - handlers.py[DEBUG]: finish: modules-final: SUCCESS: running modules for final
1 Like
72

Hello,
was anyone able to execute in-target late-commands?

I tried with

late-commands:
       - curtin in-target -- /bin/rm -f /etc/cloud/cloud.cfg.d/50-curtin-networking.cfg

image
image.png1686×286 67.2 KB 

late-commands:
  -  ["curtin", "in-target", "--", "touch /root/I_WAS_INSTALLED_WITH_AUTOINSTALL.txt"]

but with unfortunated results.

It would be great if somebody could provide the correct syntax.

73

Try to use --target=/target (I haven’t tried without it) like in my working example below:

  late-commands:
   - cp /cdrom/provisioning/provision.conf /target/etc/openvpn/
   - cp /cdrom/provisioning/provision.sh /target/tmp/
   - cp /cdrom/provisioning/amacknowledge.service /target/etc/systemd/system/
   - cp /cdrom/provisioning/amacknowledge.sh /target/usr/local/bin/
   - curtin in-target --target=/target -- /tmp/provision.sh
74

Oh thank you very much :+1: - That helped me a lot - maybe this could find its way in the documentation wiki

75

I’ve worked around all 3 problems.

1). Still can’t get apt to work properly. During the install it doesn’t use my defined local mirror. To work around that I’m using an early command that uses wget to grab a copy of the sources.list I would like and places it in /etc/apt/. However as mentioned during boot cloud-init wipes that out and places archive.ubunut.com. To get around that issue I’ve placed a sources.cfg in /target/etc/cloud/cloud.cfg.d so when cloud-init runs the first time it configures the sources.list the way I would like with the local mirror.

2). I’m using a similar method placing timzeone.cfg in to /target/etc/cloud/cloud.cfg.d so that the timezone is set when the system boots the first time.

3). I see the reason for the networking problem. The installer is creating 50-curtin-networking.cfg in /etc/cloud/cloud.cfg.d so when the system boots the first time cloud-init replaces the netplan config that the installer left with generic dhcp one mentioned previously.

1 Like
76

I’m currently struggeling with the network part of the autoinstall, because I’m having exactly the same problem as you and a few others have described; after the install the netplan is set to DHCP.

Can you tell what your workaround is and how to implement it?

Thanks!

77

I’m using two late-commands to get it done.

1). cp /etc/netplan/00-installer-config.yaml /target/etc/netplan/00-installer-config.yaml

This copies the installer netplan config in to the target system config space so it will boot with the static config being used by the installer

2). rm -rf /target/etc/cloud/cloud.cfg.d/50-curtin-networking.cfg

This is removing the dhcp config that cloud-init will use to override your netplan config.

1 Like
78

Argh, for some reason I stopped getting email notifications about posts to this thread an so missed a week’s worth of comments. Sorry about that.

There’s a lot of stuff here now and apologies if I miss something that’s been reported. I definitely encourage people to open bugs in Launchpad or start new threads here, it will be much easier to reply to everything that way.

That said

  1. there is an (embarrassing) bug around the network config not getting copied to the target system. That’s fixed in subiquity master and will be fixed in the next stable update today or tomorrow. The 50-curtin-networking.cfg file is a red herring, it’s confusing but not actually a problem. I’ll make a change to stop writing it.
  2. there should be no difference between UEFI and BIOS boots here, any differences would be a bug.
  3. as I think people realised, if you give http://x/y/z/ as a seed url, cloud-init tries to download from http://x/y/z/meta-data and http://x/y/z/user-data.
  4. if you are doing a purely net-based boot, you need to provide url=$path/to/install.iso on the kernel command line too
  5. I can’t reproduce that strange thing about interactive-sections: * vs a list of interactive-sections. I’ll keep trying though.
  6. “There is no way to verify your config beforehand” well there is a schema at https://wiki.ubuntu.com/FoundationsTeam/AutomatedServerInstalls/ConfigSchema but it’s not complete and there’s no very easy way to actually validate your user-data file against this yet, but it’s a start and we’ll make it easier to use.
  7. The documentation is incomplete in some places yes. This is a new thing though, it will improve.
  8. I’ll fix things so that you don’t need to pass --target to curtin in-target in late-commands.

I need to look into the apt config stuff, not sure what’s going on there.

1 Like
79

It’s certainly the only data source I’ve tested. Certainly the goal should be to support other sources though (that said, the expectation remains that the installer is for installing bare metal systems and cloud images are better for VMs). I think the problem might be that we have an empty nocloud seed on the installer ISO. I think you can force a particular datasource on the kernel command line, ds=ovf or something like that?

80

Hmm strange, setting the username certainly works for me via nocloud-net. I’ll try the CIDATA drive approach later, no time right now.

81

Hi everyone:

I’ve made quite a lot of progress in setting up autoinstall yaml to replace my old seed files. I’ve got a successful file that has network and storage set and I’ve been working on storage setups today (90% of all my machines use the same partitioning so I like to automate it).

I am able to do successful automated storage installs on MBR virtual machines, but I want to move forward and create a storage setup that is UEFI compatible. I can’t find any examples of this online in any cloud-init data. If someone knows of a good example of how to set properly set up the partitioning for UEFI systems using curti I would greatly appreciate it because I am guessing that I am only missing something small.

The storage setup below works in MBR mode but doesn’t work with EFI. I am testing it out with virtualbox. The error that I find when looking at the crash dump is: “autoinstall config did not create needed bootloader partition”.

storage:
version: 1
config:
  ### drive
  - id: disk0
    type: disk
    ptable: gpt
    grub_device: true
    wipe: superblock
  ### partitions
  - id: bios_boot_partition
    type: partition
    size: 1MB
    device: disk0
    flag: bios_grub
  - id: efi_partition
    type: partition
    size: 512MB
    device: disk0
    flag: boot
  - id: boot_partition
    type: partition
    size: 5GB
    device: disk0
  - id: root_partition
    type: partition
    size: -1
    device: disk0
  ### format and mount efi partitions
  - id: efi_vfat
    type: format
    fstype: fat32
    volume: efi_partition
  - id: efi_partition
    type: mount
    path: /boot/efi
    device: efi_vfat
  ### format and mount boot partition
  - id: boot_ext4
    type: format
    fstype: ext4
    volume: boot_partition
  - id: boot_mount
    type: mount
    path: /boot
    device: boot_ext4

Hopefully more experienced eyes can see what is going on here…

82

I’ve also been experimenting with this on a UEFI device. I put my full process up at https://askubuntu.com/questions/1235723/automated-20-04-server-installation-using-pxe-and-live-server-image

I don’t have the generated curtin config handy, but the autoinstall config is there

83

I think you just need to set grub_device: true on the ESP.

1 Like
84

Thanks. I think that was it. At least it was a necessary change. It’s changed my
error and I think it is typo related now.

Thanks. It’s working.
–dcl

2 Likes
85

I’ve just tried this now and it worked OK. Can you tar up /var/log/installer and maybe /var/log/cloud-init* from the installed system and attach it to a bug report?

user-data:
  timezone: Pacific/Auckland

should work.

86

Thank you so much! It worked like a charm.