Debian10 fails on final reboot

cbnorman · 26 April 2021 09:48

has anyone been able to get debian10/buster to work?

I’m using:

wget http://cdimage.debian.org/cdimage/openstack/archive/10.8.0/debian-10.8.0-openstack-amd64.raw

mkdir /mnt/custom-os-loop

mount -o rw,loop,offset=1048576,sync debian-10.8.0-openstack-amd64.raw

/mnt/custom-os-loop

cd /mnt/custom-os-loop

tar czvf /home/vagrant/debian-10.8.0-amd64.tgz .

cd /home/vagrant/

umount /mnt/custom-os-loop

maas admin boot-resources create name=custom/debian1080 title="debian-10.8.0" architecture=amd64/generic content@=/home/vagrant/debian-10.8.0-amd64.tgz

I’ve updated my curtain config /var/snap/maas/current/preseeds/curtin_userdata_custom

#cloud-config

kernel:
  fallback-package: linux-image-amd64
  package: linux-image-amd64

apt:
  preserve_sources_list: true

early_commands:
  000_update_repositories: apt update
  010_install_apt_https: apt install -y apt-transport-https ca-certificates efibootmgr xfsprogs

debconf_selections:
 maas: |
  {{for line in str(curtin_preseed).splitlines()}}
  {{line}}
  {{endfor}}

late_commands:
  maas: [wget, '--no-proxy', '{{node_disable_pxe_url}}', '--post-data', '{{node_disable_pxe_data}}', '-O', '/dev/null']

this works fine for debian9 using maas 2.9, but for debian10 it runs through all the steps does a final reboot and i can see its ready but it never marks the machine as Ready, its just stuck in a Deploying state with no errors i can find?

cbnorman · 26 April 2021 11:43

probably worth noting that i have also added net.ifnames=0 biosdevname=0 to kernel parameters in settings otherwise the network doesn’t come up.

cbnorman · 28 April 2021 17:05

It looks like cloud-init.service just doesn’t start on the final boot but i cant work out why. I’ve tried manually running cloud-init init --local and i get failed to load metadata and userdata. getting data from <class cloudinit.sources.DataSourceRbxCloud> failed.

I’m not sure it makes sense for me even trying this?

cbnorman · 29 April 2021 10:44

got a bit further with this. moving /etc/systemd/system/cloud-init.target.wants/* -> /etc/systemd/system/multi-user.target.wants/ as proposed here https://bugzilla.redhat.com/show_bug.cgi?id=1820540 in the image creation then means that cloud-init.service starts on final boot. it has an issue finding the maas datastore and i found that /etc/cloud/cloud.cfg.d/90_dpkg.cfg, /etc/cloud/cloud.cfg.d/90_dpkg_maas.cfg and /etc/cloud/cloud.cfg.d/90_dpkg_local_cloud_config.cfg do not exist.

I’m guessing these are added by the curtin install but I’m not sure why they get added on debian9 and not debian10?

cbnorman · 29 April 2021 16:40

I think due to the dpkg files missing its unable to find the maas metadata, this seems to be the problem:

journalctl -u cloud-init-local.service 
-- Logs begin at Thu 2021-04-29 15:23:45 UTC, end at Thu 2021-04-29 15:43:56 UTC. --
Apr 29 15:23:45 debian.example.com systemd[1]: Starting Initial cloud-init job (pre-networking)...
Apr 29 15:23:49 debian.example.com cloud-init[284]: Cloud-init v. 20.2 running 'init-local' at Thu, 29 Apr 2021 15:23:47 +0000. Up 7.93 seconds.
Apr 29 15:23:49 debian.example.com cloud-init[284]: 2021-04-29 15:23:49,183 - util.py[WARNING]: Failed to load metadata and userdata
Apr 29 15:23:49 debian.example.com cloud-init[284]: 2021-04-29 15:23:49,183 - util.py[WARNING]: Getting data from <class 'cloudinit.sources.DataSourceRbxCloud.DataSourceRbxCloud'>
Apr 29 15:23:49 debian.example.com systemd[1]: Started Initial cloud-init job (pre-networking).

cbnorman · 30 April 2021 14:48

@billwear did you manage to have anyone look at this. it looks like the whole cloudconfig: section from curtin_userdata_custom is getting applied. below i can see it should be setting the maas datasource with auth but on the final boot i just get data source not found and it seems to run through some default for aws 169.something

maas admin machine get-curtin-config fhk48h
Success.
Machine-readable output follows:
apt:
  preserve_sources_list: true
  proxy: http://192.168.50.10:8000/
  sources_list: 'deb http://archive.ubuntu.com/ubuntu $RELEASE multiverse restricted
    universe main

    # deb-src http://archive.ubuntu.com/ubuntu $RELEASE multiverse restricted universe
    main

    deb http://archive.ubuntu.com/ubuntu $RELEASE-updates multiverse restricted universe
    main

    # deb-src http://archive.ubuntu.com/ubuntu $RELEASE-updates multiverse restricted
    universe main

    deb http://archive.ubuntu.com/ubuntu $RELEASE-security multiverse restricted universe
    main

    # deb-src http://archive.ubuntu.com/ubuntu $RELEASE-security multiverse restricted
    universe main

    deb http://archive.ubuntu.com/ubuntu $RELEASE-backports multiverse restricted
    universe main

    # deb-src http://archive.ubuntu.com/ubuntu $RELEASE-backports multiverse restricted
    universe main

    '
cloudconfig:
  maas-cloud-config:
    content: "#cloud-config\ndatasource:\n  MAAS:\n    consumer_key: gzy3dkZFNbEnsqZxSk\n\
      \    metadata_url: http://localhost:5240/MAAS/metadata/\n    token_key: qetExRzbdP4E3J8AL2\n\
      \    token_secret: cYZdSSBDZxrbaQwP5uHR6z3w8D96G46Q\n"
    path: /etc/cloud/cloud.cfg.d/90_maas_cloud_config.cfg
  maas-datasource:
    content: 'datasource_list: [ MAAS ]'
    path: /etc/cloud/cloud.cfg.d/90_maas_datasource.cfg
  maas-reporting:
    content: "#cloud-config\nreporting:\n  maas:\n    consumer_key: gzy3dkZFNbEnsqZxSk\n\
      \    endpoint: http://localhost:5240/MAAS/metadata/status/fhk48h\n    token_key:\
      \ qetExRzbdP4E3J8AL2\n    token_secret: cYZdSSBDZxrbaQwP5uHR6z3w8D96G46Q\n \
      \   type: webhook\n"
    path: /etc/cloud/cloud.cfg.d/90_maas_cloud_init_reporting.cfg
  maas-ubuntu-sso:
    content: "#cloud-config\nsnap:\n  email: admin@admin.com\n"
    path: /etc/cloud/cloud.cfg.d/90_maas_ubuntu_sso.cfg
debconf_selections:
  grub2: grub2   grub2/update_nvram  boolean false
  maas: 'cloud-init   cloud-init/datasources  multiselect MAAS

    cloud-init   cloud-init/maas-metadata-url  string http://localhost:5240/MAAS/metadata/

    cloud-init   cloud-init/maas-metadata-credentials  string oauth_consumer_key=gzy3dkZFNbEnsqZxSk&oauth_token_key=qetExRzbdP4E3J8AL2&oauth_token_secret=cYZdSSBDZxrbaQwP5uHR6z3w8D96G46Q

    cloud-init   cloud-init/local-cloud-config  string manage_etc_hosts: true\nmanual_cache_clean:
    true\nreporting:\n  maas:\n    consumer_key: gzy3dkZFNbEnsqZxSk\n    endpoint:
    http://localhost:5240/MAAS/metadata/status/fhk48h\n    token_key: qetExRzbdP4E3J8AL2\n    token_secret:
    cYZdSSBDZxrbaQwP5uHR6z3w8D96G46Q\n    type: webhook\n

    '
install:
  error_tarfile: /tmp/curtin-logs.tar
  log_file: /tmp/install.log
  post_files:
  - /tmp/install.log
  - /tmp/curtin-logs.tar
kernel:
  fallback-package: linux-image-amd64
  package: linux-image-amd64
late_commands:
  maas:
  - wget
  - --no-proxy
  - http://localhost:5240/MAAS/metadata/latest/by-id/fhk48h/
  - --post-data
  - op=netboot_off
  - -O
  - /dev/null
network:
  config:
  - id: eth0
    mac_address: 00:0c:29:fa:03:a2
    mtu: 1500
    name: eth0
    subnets:
    - address: 192.168.50.7/24
      dns_nameservers:
      - 192.168.50.10
      dns_search: &id001
      - maas
      gateway: 192.168.50.10
      type: static
    type: physical
  - address:
    - 192.168.50.10
    search: *id001
    type: nameserver
  version: 1
network_commands:
  builtin:
  - curtin
  - net-meta
  - custom
partitioning_commands:
  builtin:
  - curtin
  - block-meta
  - custom
reporting:
  maas:
    consumer_key: gzy3dkZFNbEnsqZxSk
    endpoint: http://localhost:5240/MAAS/metadata/status/fhk48h
    token_key: qetExRzbdP4E3J8AL2
    token_secret: cYZdSSBDZxrbaQwP5uHR6z3w8D96G46Q
    type: webhook
showtrace: true
storage:
  config:
  - grub_device: true
    id: sda
    name: sda
    path: /dev/sda
    ptable: gpt
    type: disk
    wipe: superblock
  - device: sda
    flag: boot
    id: sda-part1
    name: sda-part1
    number: 1
    offset: 4194304B
    size: 536870912B
    type: partition
    uuid: cca1ae33-809b-45de-9a42-0523a0a493ef
    wipe: superblock
  - device: sda
    id: sda-part2
    name: sda-part2
    number: 2
    size: 20929576960B
    type: partition
    uuid: 2f1d0372-d4dc-4f2e-bff2-e264b8c448a1
    wipe: superblock
  - fstype: fat32
    id: sda-part1_format
    label: efi
    type: format
    uuid: d11830a9-4fc9-4ff1-a1aa-198f89aff996
    volume: sda-part1
  - fstype: ext4
    id: sda-part2_format
    label: root
    type: format
    uuid: ba050ce9-18cb-42e5-9aac-ca9c8c6c9227
    volume: sda-part2
  - device: sda-part2_format
    id: sda-part2_mount
    path: /
    type: mount
  - device: sda-part1_format
    id: sda-part1_mount
    path: /boot/efi
    type: mount
  version: 1
verbosity: 3

billwear · 30 April 2021 15:07

@cbnorman, yes. sadly, it looks like we don’t/can’t support Debian reliably on MAAS. see the discussion in this post, whose title really should be “How to deploy Debian in MAAS?” (i added the question-mark). there’s back-end development we’d have to do, which we don’t have bandwidth for atm. sorry i don’t have better news.

would an Ubuntu OS do what you want?

cbnorman · 30 April 2021 15:17

Hi @billwear I really don’t understand the discouragement on debian installs, there is a huge user base of debian users and for debian9 it works fine by just adding

apt:
  preserve_sources_list: true

in /var/snap/maas/current/preseeds/curtin_userdata_custom.

I don’t understand what the additional backend development would be? The fact that you support windows and centos but not debian which is almost the same distribution as ubuntu is crazy.

billwear · 30 April 2021 15:19

i dunno. i’ll ask those questions and let you know what i hear.

billwear · 30 April 2021 15:25

and if it’s working, it’s probably worth documenting what you’re doing in detail, or me interviewing you to get the skinny and make it (at least) part of our “tips, tricks, and traps” so others can benefit. but i’ll get back to you with the core team’s take when i connect with them.

oh, and i just assimilated your statement, “huge user base of debian users” – having a lot more info about that user base could make a difference in our thinking and focus. can you tell me more / connect me? fwiw, i’m the MAAS tech author and dev advocate, so part of my job is outreach to technical users and developers (without marketing fluff, no worries there). i’d like to engage this community of users. tia.

ltrager · 30 April 2021 17:07

Part of why MAAS doesn’t support Debian is because cloud-init and Curtin don’t have a way to differentiate between Ubuntu and Debian. This causes an issue in two areas

Installing a kernel on deployment, MAAS provides Curtin with Ubuntu kernel names
Configuring apt repository information, MAAS only supports configuring apt for Ubuntu

There are a couple of ways to fix these in MAAS however they would all rely on the image name being set to debian/$STRING. Once MAAS knows the correct string it can send the correct configuration to cloud-init and Curtin. Many users upload images with custom image names such as my-image123. MAAS has no way to know what osystem that is so it sends a generic config which includes configuring apt and installing the kernel for Ubuntu. If CentOS, RHEL, VMware, or Windows are being deployed those options get automatically ignored because apt isn’t detected.

cbnorman · 30 April 2021 17:22

Hi @ltrager thanks for taking time to explain. but i think I’m past both those issues by overriding kernel and apt in the curtin_userdata_custom.

  fallback-package: linux-image-amd64
  package: linux-image-amd64

apt:
  preserve_sources_list: true

I upload my image to maas with maas admin boot-resources create name=custom/debian1080 title="debian-10.8.0" architecture=amd64/generic content@=/home/vagrant/debian-10.8.0-amd64.tgz should i change this at all?

The problem here seems to simply just be that curtin doesn’t write the 90_dpkg*.cfg files in /etc/cloud/cloud.d/. So after successfully booting into debian, and writing any custom files I have also configured in the same curtin_userdata_custom file; it fails to contact maas from cloud-init as it has no idea about it or authentication.

I’m pretty sure this is the problem as if I follow this guide to the letter https://github.com/juan-vg/maas/wiki/Create-a-Debian-9-(Stretch)-image-that-works-with-UEFI-secure-booting. Then those files are created and it marks the deployment complete in maas. I’ve really only changing those steps to use this image http://cdimage.debian.org/cdimage/openstack/archive/10.8.0/debian-10.8.0-openstack-amd64.raw

ltrager · 3 May 2021 20:58

That command looks correct. I’m not sure why cloudconfig isn’t being written. MAAS actually provides it in two spots,debconfig_selections and cloudconfig. prevent_sources_list: true would prevent debconfig_selections from being written but cloudconfig should still work. This may be a bug in cloud-init or the Debian version of cloud-init. Another thing to keep in mind is that MAAS requires python3-oauthlib to be installed. Fedora actually removed it from cloud-init’s dependencies as MAAS is the only cloud that needs it. I would double check that its installed in the image.

cbnorman · 3 May 2021 21:25

Hi @ltrager it looks like i do have python3-oauthlib in the base image.

Reading package lists... Done
Building dependency tree       
Reading state information... Done
python3-oauthlib is already the newest version (2.1.0-1).
0 upgraded, 0 newly installed, 0 to remove and 31 not upgraded.

so I guess all that leaves is a bug in cloud-init. I’ve just used the system installed cloud-init, is it worth installing from source prehaps? I’m surprised there is no error in maas installation log pointing to the issue?

cbnorman · 3 May 2021 21:25

curtin: Installation started. (21.2-0ubuntu1~20.04.1)
start: cmd-install/stage-partitioning/builtin/cmd-block-meta: curtin command block-meta
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.123
devsync happy - path /dev/sda now exists
return volume path /dev/sda
get_path_to_storage_volume for volume sda-part1({'device': 'sda', 'flag': 'bios_grub', 'id': 'sda-part1', 'number': 1, 'offset': '4194304B', 'size': '1048576B', 'type': 'partition', 'wipe': 'zero'})
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.139
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.112
devsync happy - path /dev/sda now exists
return volume path /dev/sda1
get_path_to_storage_volume for volume sda-part2({'device': 'sda', 'id': 'sda-part2', 'name': 'sda-part2', 'number': 2, 'size': '21466447872B', 'type': 'partition', 'uuid': 'ae758758-c358-4514-8887-64b824a8632b', 'wipe': 'superblock'})
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.124
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.112
devsync happy - path /dev/sda now exists
return volume path /dev/sda2
block-meta: extracted devices to clear: ['/dev/sda', '/dev/sda1', '/dev/sda2']
Declared block devices: ['/dev/sda', '/dev/sda1', '/dev/sda2']
clearing devices=['/dev/sda', '/dev/sda1', '/dev/sda2']
start: cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders: removing previous storage devices
Running command ['mdadm', '--assemble', '--scan', '-v'] with allowed return codes [0, 1, 2] (capture=True)
mdadm assemble scan results:

mdadm: looking for devices for further assembly
mdadm: no recogniseable superblock on /dev/sda2
mdadm: no recogniseable superblock on /dev/sda1
mdadm: Cannot assemble mbr metadata on /dev/sda
mdadm: cannot open device /dev/sr0: No medium found
mdadm: no recogniseable superblock on /dev/loop3
mdadm: no recogniseable superblock on /dev/loop2
mdadm: no recogniseable superblock on /dev/loop1
mdadm: no recogniseable superblock on /dev/loop0
mdadm: No arrays found in config file or automatically

Running command ['mdadm', '--detail', '--scan', '-v'] with allowed return codes [0, 1] (capture=True)
mdadm detail scan after assemble:


Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.008
Detected multipath support, reload maps
Running command ['multipath', '-r'] with allowed return codes [0] (capture=False)
Verifying /dev/mapper/mpath* files are symlinks
Running command ['dmsetup', 'ls', '-o', 'blkdevname'] with allowed return codes [0] (capture=True)
Running command ['pvscan', '--config', 'devices{ filter = [ "a|/dev/mapper/mpath.*|", "r|.*|" ] }'] with allowed return codes [0] (capture=True)
Running command ['vgscan', '--config', 'devices{ filter = [ "a|/dev/mapper/mpath.*|", "r|.*|" ] }'] with allowed return codes [0] (capture=True)
Running command ['vgchange', '--activate=y', '--config', 'devices{ filter = [ "a|/dev/mapper/mpath.*|", "r|.*|" ] }'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.021
Loading kernel module bcache via modprobe
Running command ['modprobe', '--use-blacklist', 'bcache'] with allowed return codes [0] (capture=False)
Generating device storage trees for path(s): ['/dev/sda', '/dev/sda1', '/dev/sda2']
devname '/sys/class/block/sda' had holders: []
/dev/sda is multipath device partition? False
/dev/sda is multipath device partition? False
/dev/sda is multipath device partition? False
devname '/sys/class/block/sda2' had holders: []
devname '/sys/class/block/sda1' had holders: []
devname '/sys/class/block/sda1' had holders: []
devname '/sys/class/block/sda2' had holders: []
Current device storage tree:
sda
|-- sda2
`-- sda1
sda1
sda2
Shutdown Plan:
{'level': 3, 'device': '/sys/class/block/sda2', 'dev_type': 'partition'}
{'level': 3, 'device': '/sys/class/block/sda1', 'dev_type': 'partition'}
{'level': 1, 'device': '/sys/class/block/sda', 'dev_type': 'disk'}
shutdown running on holder type: 'partition' syspath: '/sys/class/block/sda2'
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda'] with allowed return codes [0] (capture=True)
get_blockdev_sector_size: info:
{
 "sda": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:0",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "VMware_Virtual_S",
  "MOUNTPOINT": "",
  "NAME": "sda",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21474836480",
  "STATE": "running",
  "TYPE": "disk",
  "UUID": "",
  "device_path": "/dev/sda"
 },
 "sda1": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda1",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:1",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda1",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "1048576",
  "STATE": "",
  "TYPE": "part",
  "UUID": "",
  "device_path": "/dev/sda1"
 },
 "sda2": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "ext4",
  "GROUP": "disk",
  "KNAME": "sda2",
  "LABEL": "root",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:2",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda2",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21472722432",
  "STATE": "",
  "TYPE": "part",
  "UUID": "e83cada8-a344-4def-9db1-b0d00cbf1840",
  "device_path": "/dev/sda2"
 }
}
get_blockdev_sector_size: (log=512, phys=512)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID'] with allowed return codes [0] (capture=True)
Checking if /dev/sda2 is a swap device
Found swap magic: b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda2'] with allowed return codes [0] (capture=True)
/dev/sda2 is multipath device? False
Running command ['multipath', '-c', '/dev/sda2'] with allowed return codes [0] (capture=True)
/dev/sda2 is multipath device member? False
wiping superblock on /dev/sda2
wiping /dev/sda2 attempt 1/4
wiping 1M on /dev/sda2 at offsets [0, -1048576]
successfully wiped device /dev/sda2 on attempt 1/4
shutdown running on holder type: 'partition' syspath: '/sys/class/block/sda1'
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda'] with allowed return codes [0] (capture=True)
get_blockdev_sector_size: info:
{
 "sda": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:0",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "VMware_Virtual_S",
  "MOUNTPOINT": "",
  "NAME": "sda",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21474836480",
  "STATE": "running",
  "TYPE": "disk",
  "UUID": "",
  "device_path": "/dev/sda"
 },
 "sda1": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda1",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:1",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda1",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "1048576",
  "STATE": "",
  "TYPE": "part",
  "UUID": "",
  "device_path": "/dev/sda1"
 },
 "sda2": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "ext4",
  "GROUP": "disk",
  "KNAME": "sda2",
  "LABEL": "root",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:2",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda2",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21472722432",
  "STATE": "",
  "TYPE": "part",
  "UUID": "e83cada8-a344-4def-9db1-b0d00cbf1840",
  "device_path": "/dev/sda2"
 }
}
get_blockdev_sector_size: (log=512, phys=512)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID'] with allowed return codes [0] (capture=True)
Checking if /dev/sda1 is a swap device
Found swap magic: b'\x7fP&\x0c\xa1\r\x8dR\x00"'
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda1'] with allowed return codes [0] (capture=True)
/dev/sda1 is multipath device? False
Running command ['multipath', '-c', '/dev/sda1'] with allowed return codes [0] (capture=True)
/dev/sda1 is multipath device member? False
wiping superblock on /dev/sda1
wiping /dev/sda1 attempt 1/4
wiping 1M on /dev/sda1 at offsets [0, -1048576]
successfully wiped device /dev/sda1 on attempt 1/4
shutdown running on holder type: 'disk' syspath: '/sys/class/block/sda'
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda'] with allowed return codes [0] (capture=True)
get_blockdev_sector_size: info:
{
 "sda": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:0",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "VMware_Virtual_S",
  "MOUNTPOINT": "",
  "NAME": "sda",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21474836480",
  "STATE": "running",
  "TYPE": "disk",
  "UUID": "",
  "device_path": "/dev/sda"
 },
 "sda1": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda1",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:1",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda1",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "1048576",
  "STATE": "",
  "TYPE": "part",
  "UUID": "",
  "device_path": "/dev/sda1"
 },
 "sda2": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda2",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:2",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda2",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21472722432",
  "STATE": "",
  "TYPE": "part",
  "UUID": "",
  "device_path": "/dev/sda2"
 }
}
get_blockdev_sector_size: (log=512, phys=512)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID'] with allowed return codes [0] (capture=True)
Checking if /dev/sda is a swap device
Found swap magic: b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device? False
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
wiping superblock on /dev/sda
wiping /dev/sda attempt 1/4
wiping 1M on /dev/sda at offsets [0, -1048576]
successfully wiped device /dev/sda on attempt 1/4
/sys/class/block/sda had partitions, issuing partition reread
Running command ['blockdev', '--rereadpt', '/dev/sda'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.076
block.sys_block_path: devname /dev/sda1 does not exist
block.sys_block_path: devname /dev/sda2 does not exist
devname '/sys/class/block/sda' had holders: []
/dev/sda is multipath device partition? False
/dev/sda is multipath device partition? False
/dev/sda is multipath device partition? False
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta/clear-holders: SUCCESS: removing previous storage devices
blockmeta: detected storage config, using mode=custom
start: cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring disk: sda
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.075
devsync happy - path /dev/sda now exists
return volume path /dev/sda
wiping 1M on /dev/sda at offsets [0, -1048576]
labeling device: '/dev/sda' with 'gpt' partition table
wiping 1M on /dev/sda at offsets [0, -1048576]
devname '/dev/sda' had holders: []
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.072
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['blkid', '-o', 'export', '/dev/sda'] with allowed return codes [0, 2] (capture=True)
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda'] with allowed return codes [0] (capture=True)
Cannot create disk tag udev rule for /dev/sda [id=sda], missing 'serial' or 'wwn' value
Can't find a uuid for volume: sda. Skipping dname.
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring disk: sda
start: cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring partition: sda-part1
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.044
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda'] with allowed return codes [0] (capture=True)
get_blockdev_sector_size: info:
{
 "sda": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:0",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "VMware_Virtual_S",
  "MOUNTPOINT": "",
  "NAME": "sda",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21474836480",
  "STATE": "running",
  "TYPE": "disk",
  "UUID": "",
  "device_path": "/dev/sda"
 }
}
get_blockdev_sector_size: (log=512, phys=512)
sda logical_block_size_bytes: 512
adding partition 'sda-part1' to disk 'sda' (ptable: 'gpt')
partnum: 1 offset_sectors: 2048 length_sectors: 2047
Preparing partition location on disk /dev/sda
Wiping 1M on /dev/sda at offset 1048576
Running command ['sgdisk', '--new', '1:2048:4095', '--typecode=1:ef02', '/dev/sda'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device? False
Running command ['blockdev', '--rereadpt', '/dev/sda'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.123
TIMED udevadm_settle(exists='/dev/sda1'): 0.000
Wiping partition /dev/sda1 mode=zero
/dev/sda1 is 1048576 bytes. wiping with buflen=4194304
get_path_to_storage_volume for volume sda-part1({'device': 'sda', 'flag': 'bios_grub', 'id': 'sda-part1', 'number': 1, 'offset': '4194304B', 'size': '1048576B', 'type': 'partition', 'wipe': 'zero'})
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.080
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.084
devsync happy - path /dev/sda now exists
return volume path /dev/sda1
Running command ['blkid', '-o', 'export', '/dev/sda1'] with allowed return codes [0, 2] (capture=True)
No partition-specific dname
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring partition: sda-part1
start: cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring partition: sda-part2
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.080
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda'] with allowed return codes [0] (capture=True)
get_blockdev_sector_size: info:
{
 "sda": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:0",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "VMware_Virtual_S",
  "MOUNTPOINT": "",
  "NAME": "sda",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21474836480",
  "STATE": "running",
  "TYPE": "disk",
  "UUID": "",
  "device_path": "/dev/sda"
 },
 "sda1": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda1",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:1",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda1",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "1048576",
  "STATE": "",
  "TYPE": "part",
  "UUID": "",
  "device_path": "/dev/sda1"
 }
}
get_blockdev_sector_size: (log=512, phys=512)
sda logical_block_size_bytes: 512
previous partition number for 'sda-part2' found to be '1'
partition_kname=sda1
calc_partition_info: sda1 size_sectors=2048 start_sectors=2048
adding partition 'sda-part2' to disk 'sda' (ptable: 'gpt')
partnum: 2 offset_sectors: 4096 length_sectors: 41926655
Preparing partition location on disk /dev/sda
Wiping 1M on /dev/sda at offset 2097152
Running command ['sgdisk', '--new', '2:4096:41930751', '--typecode=2:8300', '/dev/sda'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device? False
Running command ['blockdev', '--rereadpt', '/dev/sda'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.185
TIMED udevadm_settle(exists='/dev/sda2'): 0.000
get_path_to_storage_volume for volume sda-part2({'device': 'sda', 'id': 'sda-part2', 'name': 'sda-part2', 'number': 2, 'size': '21466447872B', 'type': 'partition', 'uuid': 'ae758758-c358-4514-8887-64b824a8632b', 'wipe': 'superblock'})
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.120
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.115
devsync happy - path /dev/sda now exists
return volume path /dev/sda2
Running command ['blkid', '-o', 'export', '/dev/sda2'] with allowed return codes [0, 2] (capture=True)
Creating dname udev rule '['SUBSYSTEM=="block"', 'ACTION=="add|change"', 'ENV{DEVTYPE}=="partition"', 'ENV{ID_PART_ENTRY_UUID}=="bf1d48a0-5e16-42bc-910e-cca6e6568eb4"', 'SYMLINK+="disk/by-dname/sda-part2"\n']'
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring partition: sda-part2
start: cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring format: sda-part2_format
get_path_to_storage_volume for volume sda-part2({'device': 'sda', 'id': 'sda-part2', 'name': 'sda-part2', 'number': 2, 'size': '21466447872B', 'type': 'partition', 'uuid': 'ae758758-c358-4514-8887-64b824a8632b', 'wipe': 'superblock'})
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.123
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.124
devsync happy - path /dev/sda now exists
return volume path /dev/sda2
mkfs /dev/sda2 info: {'fstype': 'ext4', 'id': 'sda-part2_format', 'label': 'root', 'type': 'format', 'uuid': 'e83cada8-a344-4def-9db1-b0d00cbf1840', 'volume': 'sda-part2'}
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda2'] with allowed return codes [0] (capture=True)
get_blockdev_sector_size: info:
{
 "sda2": {
  "ALIGNMENT": "0",
  "DISC-ALN": "0",
  "DISC-GRAN": "0",
  "DISC-MAX": "0",
  "DISC-ZERO": "0",
  "FSTYPE": "",
  "GROUP": "disk",
  "KNAME": "sda2",
  "LABEL": "",
  "LOG-SEC": "512",
  "MAJ:MIN": "8:2",
  "MIN-IO": "512",
  "MODE": "brw-rw----",
  "MODEL": "",
  "MOUNTPOINT": "",
  "NAME": "sda2",
  "OPT-IO": "0",
  "OWNER": "root",
  "PHY-SEC": "512",
  "RM": "0",
  "RO": "0",
  "ROTA": "1",
  "RQ-SIZE": "254",
  "SIZE": "21466447872",
  "STATE": "",
  "TYPE": "part",
  "UUID": "",
  "device_path": "/dev/sda2"
 }
}
get_blockdev_sector_size: (log=512, phys=512)
Running command ['mkfs.ext4', '-F', '-L', 'root', '-U', 'e83cada8-a344-4def-9db1-b0d00cbf1840', '/dev/sda2'] with allowed return codes [0] (capture=True)
Formated device type: partition
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring format: sda-part2_format
start: cmd-install/stage-partitioning/builtin/cmd-block-meta: configuring mount: sda-part2_mount
get_path_to_storage_volume for volume sda-part2({'device': 'sda', 'id': 'sda-part2', 'name': 'sda-part2', 'number': 2, 'size': '21466447872B', 'type': 'partition', 'uuid': 'ae758758-c358-4514-8887-64b824a8632b', 'wipe': 'superblock'})
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.150
devsync happy - path /dev/sda now exists
return volume path /dev/sda
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.112
devsync happy - path /dev/sda now exists
return volume path /dev/sda2
volume_path=/dev/sda2 found slaves: ['sda2']
kname_is_iscsi: no iscsi disk found for kname sda2
kname_is_iscsi: no iscsi disk found for kname sda2
Running command ['mount', '-t', 'ext4', '-o', 'defaults', '/dev/sda2', '/tmp/tmpv203or18/target/'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda2'] with allowed return codes [0] (capture=True)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda2'] with allowed return codes [0] (capture=True)
volspec: path=/dev/sda2 type=part
info[DEVLINKS] = ['/dev/disk/by-path/pci-0000:00:10.0-scsi-0:0:0:0-part2', '/dev/disk/by-uuid/e83cada8-a344-4def-9db1-b0d00cbf1840', '/dev/disk/by-label/root', '/dev/disk/by-partuuid/bf1d48a0-5e16-42bc-910e-cca6e6568eb4']
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: configuring mount: sda-part2_mount
TIMED BLOCK_META: 6.772
finish: cmd-install/stage-partitioning/builtin/cmd-block-meta: SUCCESS: curtin command block-meta
start: cmd-install/stage-network/builtin/cmd-net-meta: curtin command net-meta
net-meta mode is 'custom'.  devices=[]
writing to file /tmp/tmpv203or18/state/network_config with network config: network:
  config:
  - id: eth0
    mac_address: 00:0c:29:d9:0d:c5
    mtu: 1500
    name: eth0
    subnets:
    - address: 192.168.50.33/24
      dns_nameservers:
      - 192.168.50.10
      dns_search:
      - maas
      gateway: 192.168.50.10
      type: static
    type: physical
  - address:
    - 192.168.50.10
    search:
    - maas
    type: nameserver
  version: 1

finish: cmd-install/stage-network/builtin/cmd-net-meta: SUCCESS: curtin command net-meta
start: cmd-install/stage-extract/builtin/cmd-extract: curtin command extract
Installing sources: [{'type': 'tgz', 'uri': 'http://192.168.50.10:5248/images/custom/amd64/generic/debian1080/uploaded/root-tgz'}] to target at /tmp/tmpv203or18/target
start: cmd-install/stage-extract/builtin/cmd-extract: acquiring and extracting image from http://192.168.50.10:5248/images/custom/amd64/generic/debian1080/uploaded/root-tgz
Running command ['tar', '--help'] with allowed return codes [0] (capture=True)
Running command ['sh', '-cf', 'wget "$1" --progress=dot:mega -O - |smtar -C "$2" --xattrs --xattrs-include=* -Sxpf - --numeric-owner', '--', 'http://192.168.50.10:5248/images/custom/amd64/generic/debian1080/uploaded/root-tgz', '/tmp/tmpv203or18/target'] with allowed return codes [0] (capture=False)
--2021-05-02 23:01:57--  http://192.168.50.10:5248/images/custom/amd64/generic/debian1080/uploaded/root-tgz
Connecting to 192.168.50.10:5248... connected.
HTTP request sent, awaiting response... 200 OK
Length: 336671088 (321M) [application/octet-stream]
Saving to: ‘STDOUT’

     0K ........ ........ ........ ........ ........ ........  0% 24.9M 13s
  3072K ........ ........ ........ ........ ........ ........  1% 32.0M 11s
  6144K ........ ........ ........ ........ ........ ........  2% 32.6M 11s
  9216K ........ ........ ........ ........ ........ ........  3% 26.5M 11s
 12288K ........ ........ ........ ........ ........ ........  4% 26.8M 11s
 15360K ........ ........ ........ ........ ........ ........  5% 28.9M 11s
 18432K ........ ........ ........ ........ ........ ........  6% 38.7M 10s
 21504K ........ ........ ........ ........ ........ ........  7% 34.5M 10s
 24576K ........ ........ ........ ........ ........ ........  8% 30.2M 10s
 27648K ........ ........ ........ ........ ........ ........  9% 28.5M 10s
 30720K ........ ........ ........ ........ ........ ........ 10% 33.0M 10s
 33792K ........ ........ ........ ........ ........ ........ 11% 21.9M 10s
 36864K ........ ........ ........ ........ ........ ........ 12% 32.6M 10s
 39936K ........ ........ ........ ........ ........ ........ 13% 30.7M 9s
 43008K ........ ........ ........ ........ ........ ........ 14% 24.5M 9s
 46080K ........ ........ ........ ........ ........ ........ 14% 27.4M 9s
 49152K ........ ........ ........ ........ ........ ........ 15% 20.7M 10s
 52224K ........ ........ ........ ........ ........ ........ 16% 23.6M 10s
 55296K ........ ........ ........ ........ ........ ........ 17% 16.0M 10s
 58368K ........ ........ ........ ........ ........ ........ 18% 23.9M 10s
 61440K ........ ........ ........ ........ ........ ........ 19% 17.0M 10s
 64512K ........ ........ ........ ........ ........ ........ 20% 23.8M 10s
 67584K ........ ........ ........ ........ ........ ........ 21% 27.6M 10s
 70656K ........ ........ ........ ........ ........ ........ 22% 22.7M 10s
 73728K ........ ........ ........ ........ ........ ........ 23% 26.1M 10s
 76800K ........ ........ ........ ........ ........ ........ 24% 18.8M 10s
 79872K ........ ........ ........ ........ ........ ........ 25% 24.9M 9s
 82944K ........ ........ ........ ........ ........ ........ 26% 24.7M 9s
 86016K ........ ........ ........ ........ ........ ........ 27% 26.3M 9s
 89088K ........ ........ ........ ........ ........ ........ 28% 24.6M 9s
 92160K ........ ........ ........ ........ ........ ........ 28% 20.2M 9s
 95232K ........ ........ ........ ........ ........ ........ 29% 22.0M 9s
 98304K ........ ........ ........ ........ ........ ........ 30% 23.7M 9s
101376K ........ ........ ........ ........ ........ ........ 31% 14.6M 9s
104448K ........ ........ ........ ........ ........ ........ 32% 23.3M 9s
107520K ........ ........ ........ ........ ........ ........ 33% 24.7M 9s
110592K ........ ........ ........ ........ ........ ........ 34% 24.1M 9s
113664K ........ ........ ........ ........ ........ ........ 35% 27.3M 8s
116736K ........ ........ ........ ........ ........ ........ 36% 20.5M 8s
119808K ........ ........ ........ ........ ........ ........ 37% 28.6M 8s
122880K ........ ........ ........ ........ ........ ........ 38% 38.9M 8s
125952K ........ ........ ........ ........ ........ ........ 39% 21.1M 8s
129024K ........ ........ ........ ........ ........ ........ 40% 33.1M 8s
132096K ........ ........ ........ ........ ........ ........ 41% 38.8M 8s
135168K ........ ........ ........ ........ ........ ........ 42% 41.9M 7s
138240K ........ ........ ........ ........ ........ ........ 42% 43.4M 7s
141312K ........ ........ ........ ........ ........ ........ 43% 44.0M 7s
144384K ........ ........ ........ ........ ........ ........ 44% 37.9M 7s
147456K ........ ........ ........ ........ ........ ........ 45% 41.2M 7s
150528K ........ ........ ........ ........ ........ ........ 46% 20.6M 7s
153600K ........ ........ ........ ........ ........ ........ 47% 36.8M 6s
156672K ........ ........ ........ ........ ........ ........ 48% 28.2M 6s
159744K ........ ........ ........ ........ ........ ........ 49% 30.1M 6s
162816K ........ ........ ........ ........ ........ ........ 50% 38.3M 6s
165888K ........ ........ ........ ........ ........ ........ 51% 27.9M 6s
168960K ........ ........ ........ ........ ........ ........ 52% 32.0M 6s
172032K ........ ........ ........ ........ ........ ........ 53% 33.1M 6s
175104K ........ ........ ........ ........ ........ ........ 54% 34.1M 6s
178176K ........ ........ ........ ........ ........ ........ 55% 31.8M 5s
181248K ........ ........ ........ ........ ........ ........ 56% 29.2M 5s
184320K ........ ........ ........ ........ ........ ........ 56% 33.6M 5s
187392K ........ ........ ........ ........ ........ ........ 57% 18.0M 5s
190464K ........ ........ ........ ........ ........ ........ 58% 48.3M 5s
193536K ........ ........ ........ ........ ........ ........ 59% 28.2M 5s
196608K ........ ........ ........ ........ ........ ........ 60% 33.1M 5s
199680K ........ ........ ........ ........ ........ ........ 61% 30.5M 5s
202752K ........ ........ ........ ........ ........ ........ 62% 27.5M 4s
205824K ........ ........ ........ ........ ........ ........ 63% 30.8M 4s
208896K ........ ........ ........ ........ ........ ........ 64% 60.0M 4s
211968K ........ ........ ........ ........ ........ ........ 65% 53.1M 4s
215040K ........ ........ ........ ........ ........ ........ 66% 63.2M 4s
218112K ........ ........ ........ ........ ........ ........ 67% 56.0M 4s
221184K ........ ........ ........ ........ ........ ........ 68% 47.5M 4s
224256K ........ ........ ........ ........ ........ ........ 69% 53.9M 4s
227328K ........ ........ ........ ........ ........ ........ 70% 39.6M 3s
230400K ........ ........ ........ ........ ........ ........ 71% 39.9M 3s
233472K ........ ........ ........ ........ ........ ........ 71% 65.6M 3s
236544K ........ ........ ........ ........ ........ ........ 72% 78.3M 3s
239616K ........ ........ ........ ........ ........ ........ 73% 79.1M 3s
242688K ........ ........ ........ ........ ........ ........ 74% 40.4M 3s
245760K ........ ........ ........ ........ ........ ........ 75% 34.5M 3s
248832K ........ ........ ........ ........ ........ ........ 76% 81.3M 3s
251904K ........ ........ ........ ........ ........ ........ 77% 27.7M 2s
254976K ........ ........ ........ ........ ........ ........ 78% 29.9M 2s
258048K ........ ........ ........ ........ ........ ........ 79% 29.0M 2s
261120K ........ ........ ........ ........ ........ ........ 80% 27.2M 2s
264192K ........ ........ ........ ........ ........ ........ 81% 22.6M 2s
267264K ........ ........ ........ ........ ........ ........ 82% 31.4M 2s
270336K ........ ........ ........ ........ ........ ........ 83% 29.6M 2s
273408K ........ ........ ........ ........ ........ ........ 84% 27.8M 2s
276480K ........ ........ ........ ........ ........ ........ 85% 29.1M 2s
279552K ........ ........ ........ ........ ........ ........ 85% 28.8M 2s
282624K ........ ........ ........ ........ ........ ........ 86% 28.4M 1s
285696K ........ ........ ........ ........ ........ ........ 87% 26.1M 1s
288768K ........ ........ ........ ........ ........ ........ 88% 28.1M 1s
291840K ........ ........ ........ ........ ........ ........ 89% 25.4M 1s
294912K ........ ........ ........ ........ ........ ........ 90% 26.6M 1s
297984K ........ ........ ........ ........ ........ ........ 91% 25.7M 1s
301056K ........ ........ ........ ........ ........ ........ 92% 35.5M 1s
304128K ........ ........ ........ ........ ........ ........ 93% 35.1M 1s
307200K ........ ........ ........ ........ ........ ........ 94% 31.4M 1s
310272K ........ ........ ........ ........ ........ ........ 95% 34.2M 1s
313344K ........ ........ ........ ........ ........ ........ 96% 26.2M 0s
316416K ........ ........ ........ ........ ........ ........ 97% 34.5M 0s
319488K ........ ........ ........ ........ ........ ........ 98% 34.1M 0s
322560K ........ ........ ........ ........ ........ ........ 99% 34.6M 0s
325632K ........ ........ ........ ........ ........ ........ 99% 38.1M 0s
328704K .                                                    100% 7.76M=11s

2021-05-02 23:02:08 (29.5 MB/s) - written to stdout [336671088/336671088]

finish: cmd-install/stage-extract/builtin/cmd-extract: SUCCESS: acquiring and extracting image from http://192.168.50.10:5248/images/custom/amd64/generic/debian1080/uploaded/root-tgz
Applying write_files from config.
finish: cmd-install/stage-extract/builtin/cmd-extract: SUCCESS: curtin command extract
start: cmd-install/stage-curthooks/builtin/cmd-curthooks: curtin command curthooks
Running curtin builtin curthooks
Configuring target system for distro: debian osfamily: debian
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-apt-config: configuring apt configuring apt
Transferred {'grub2': 'grub2   grub2/update_nvram  boolean false', 'maas': 'cloud-init   cloud-init/datasources  multiselect MAAS\ncloud-init   cloud-init/maas-metadata-url  string http://192.168.50.10:5248/MAAS/metadata/\ncloud-init   cloud-init/maas-metadata-credentials  string oauth_consumer_key=eGJp7H8Ad77KZVYp6z&oauth_token_key=NPQ3CUYPyJbGQWabAy&oauth_token_secret=9V3E6nuvmEpuASLGPmBqA6VCgrbPcwak\ncloud-init   cloud-init/local-cloud-config  string manage_etc_hosts: true\\nmanual_cache_clean: true\\nreporting:\\n  maas:\\n    consumer_key: eGJp7H8Ad77KZVYp6z\\n    endpoint: http://192.168.50.10:5248/MAAS/metadata/status/7s6r6d\\n    token_key: NPQ3CUYPyJbGQWabAy\\n    token_secret: 9V3E6nuvmEpuASLGPmBqA6VCgrbPcwak\\n    type: webhook\\n\n'} into new format: {'preserve_sources_list': True, 'proxy': 'http://192.168.50.10:8000/', 'sources_list': 'deb http://archive.ubuntu.com/ubuntu $RELEASE universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE universe multiverse main restricted\ndeb http://archive.ubuntu.com/ubuntu $RELEASE-updates universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE-updates universe multiverse main restricted\ndeb http://archive.ubuntu.com/ubuntu $RELEASE-security universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE-security universe multiverse main restricted\ndeb http://archive.ubuntu.com/ubuntu $RELEASE-backports universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE-backports universe multiverse main restricted\n', 'debconf_selections': {'grub2': 'grub2   grub2/update_nvram  boolean false', 'maas': 'cloud-init   cloud-init/datasources  multiselect MAAS\ncloud-init   cloud-init/maas-metadata-url  string http://192.168.50.10:5248/MAAS/metadata/\ncloud-init   cloud-init/maas-metadata-credentials  string oauth_consumer_key=eGJp7H8Ad77KZVYp6z&oauth_token_key=NPQ3CUYPyJbGQWabAy&oauth_token_secret=9V3E6nuvmEpuASLGPmBqA6VCgrbPcwak\ncloud-init   cloud-init/local-cloud-config  string manage_etc_hosts: true\\nmanual_cache_clean: true\\nreporting:\\n  maas:\\n    consumer_key: eGJp7H8Ad77KZVYp6z\\n    endpoint: http://192.168.50.10:5248/MAAS/metadata/status/7s6r6d\\n    token_key: NPQ3CUYPyJbGQWabAy\\n    token_secret: 9V3E6nuvmEpuASLGPmBqA6VCgrbPcwak\\n    type: webhook\\n\n'}}
curthooks handling apt to target /tmp/tmpv203or18/target with config {'preserve_sources_list': True, 'proxy': 'http://192.168.50.10:8000/', 'sources_list': 'deb http://archive.ubuntu.com/ubuntu $RELEASE universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE universe multiverse main restricted\ndeb http://archive.ubuntu.com/ubuntu $RELEASE-updates universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE-updates universe multiverse main restricted\ndeb http://archive.ubuntu.com/ubuntu $RELEASE-security universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE-security universe multiverse main restricted\ndeb http://archive.ubuntu.com/ubuntu $RELEASE-backports universe multiverse main restricted\n# deb-src http://archive.ubuntu.com/ubuntu $RELEASE-backports universe multiverse main restricted\n', 'debconf_selections': {'grub2': 'grub2   grub2/update_nvram  boolean false', 'maas': 'cloud-init   cloud-init/datasources  multiselect MAAS\ncloud-init   cloud-init/maas-metadata-url  string http://192.168.50.10:5248/MAAS/metadata/\ncloud-init   cloud-init/maas-metadata-credentials  string oauth_consumer_key=eGJp7H8Ad77KZVYp6z&oauth_token_key=NPQ3CUYPyJbGQWabAy&oauth_token_secret=9V3E6nuvmEpuASLGPmBqA6VCgrbPcwak\ncloud-init   cloud-init/local-cloud-config  string manage_etc_hosts: true\\nmanual_cache_clean: true\\nreporting:\\n  maas:\\n    consumer_key: eGJp7H8Ad77KZVYp6z\\n    endpoint: http://192.168.50.10:5248/MAAS/metadata/status/7s6r6d\\n    token_key: NPQ3CUYPyJbGQWabAy\\n    token_secret: 9V3E6nuvmEpuASLGPmBqA6VCgrbPcwak\\n    type: webhook\\n\n'}}
Running command ['unshare', '--help'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'lsb_release', '--all'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg', '--print-architecture'] with allowed return codes [0] (capture=True)
got primary mirror: None
got security mirror: None
Apt Mirror info: {'PRIMARY': 'http://archive.ubuntu.com/ubuntu/', 'SECURITY': 'http://security.ubuntu.com/ubuntu/', 'MIRROR': 'http://archive.ubuntu.com/ubuntu/'}
Applying debconf selections
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'debconf-set-selections'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-query', '--list'] with allowed return codes [0] (capture=True)
unconfiguring cloud-init
cleaning cloud-init config from: ['/tmp/tmpv203or18/target/etc/cloud/cloud.cfg.d/90_dpkg.cfg']
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-reconfigure', '--frontend=noninteractive', 'cloud-init'] with allowed return codes [0] (capture=True)
write apt proxy info to /tmp/tmpv203or18/target/etc/apt/apt.conf.d/90curtin-aptproxy
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Diverting original update-initramfs in target.
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-divert', '--add', '--rename', '--divert', '/usr/sbin/update-initramfs.curtin-disabled', '/usr/sbin/update-initramfs'] with allowed return codes [0] (capture=False)
Adding 'local diversion of /usr/sbin/update-initramfs to /usr/sbin/update-initramfs.curtin-disabled'
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.045
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-apt-config: SUCCESS: configuring apt configuring apt
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'lsb_release', '--all'] with allowed return codes [0] (capture=True)
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-missing-packages: installing missing packages
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-query', '--list'] with allowed return codes [0] (capture=True)
Curtin config dependencies requires additional packages: ['e2fsprogs']
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-missing-packages: SUCCESS: installing missing packages
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-iscsi-service: configuring iscsi service
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-iscsi-service: SUCCESS: configuring iscsi service
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-mdadm-service: configuring raid (mdadm) service
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-mdadm-service: SUCCESS: configuring raid (mdadm) service
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-kernel: installing kernel
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'lsb_release', '--all'] with allowed return codes [0] (capture=True)
Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (capture=True)
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'apt-get', '--quiet', '--option=Acquire::Languages=none', '--option=Dir::Etc::sourcelist=/tmp/tmpgbast0il/sources.list', '--option=Dir::Etc::sourceparts=/tmp/tmpgbast0il/sources.list.d', 'update'] with allowed return codes [0] (capture=False)
Hit:1 http://ftp.debian.org/debian buster InRelease
Hit:2 http://deb.debian.org/debian buster InRelease
Get:3 http://deb.debian.org/debian buster-updates InRelease [51.9 kB]
Get:4 http://security.debian.org/debian-security buster/updates InRelease [65.4 kB]
Get:5 http://security.debian.org/debian-security buster/updates/main amd64 Packages [285 kB]
Fetched 402 kB in 0s (874 kB/s)
Reading package lists...
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.019
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'apt-get', '--quiet', '--assume-yes', '--option=Dpkg::options::=--force-unsafe-io', '--option=Dpkg::Options::=--force-confold', 'install', 'linux-image-amd64'] with allowed return codes [0] (capture=False)
Reading package lists...
Building dependency tree...
Reading state information...
The following additional packages will be installed:
  linux-image-4.19.0-16-amd64
Suggested packages:
  linux-doc-4.19 debian-kernel-handbook
The following NEW packages will be installed:
  linux-image-4.19.0-16-amd64 linux-image-amd64
0 upgraded, 2 newly installed, 0 to remove and 31 not upgraded.
Need to get 48.4 MB of archives.
After this operation, 270 MB of additional disk space will be used.
Get:1 http://deb.debian.org/debian buster/main amd64 linux-image-4.19.0-16-amd64 amd64 4.19.181-1 [48.4 MB]
Get:2 http://deb.debian.org/debian buster/main amd64 linux-image-amd64 amd64 4.19+105+deb10u11 [8288 B]
Fetched 48.4 MB in 1s (85.7 MB/s)
E: Can not write log (Is /dev/pts mounted?) - posix_openpt (19: No such device)
Selecting previously unselected package linux-image-4.19.0-16-amd64.
(Reading database ... 27129 files and directories currently installed.)
Preparing to unpack .../linux-image-4.19.0-16-amd64_4.19.181-1_amd64.deb ...
Unpacking linux-image-4.19.0-16-amd64 (4.19.181-1) ...
Selecting previously unselected package linux-image-amd64.
Preparing to unpack .../linux-image-amd64_4.19+105+deb10u11_amd64.deb ...
Unpacking linux-image-amd64 (4.19+105+deb10u11) ...
Setting up linux-image-4.19.0-16-amd64 (4.19.181-1) ...
I: /vmlinuz is now a symlink to boot/vmlinuz-4.19.0-16-amd64
I: /initrd.img is now a symlink to boot/initrd.img-4.19.0-16-amd64
/etc/kernel/postinst.d/zz-update-grub:
Generating grub configuration file ...
Found linux image: /boot/vmlinuz-4.19.0-16-amd64
Found linux image: /boot/vmlinuz-4.19.0-14-cloud-amd64
Found initrd image: /boot/initrd.img-4.19.0-14-cloud-amd64
done
Setting up linux-image-amd64 (4.19+105+deb10u11) ...
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'apt-get', 'clean'] with allowed return codes [0] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.019
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/installing-kernel: SUCCESS: installing kernel
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/setting-up-swap: setting up swap
Running command ['findmnt', '--noheading', '--target', '/tmp/tmpv203or18/target/', '-o', 'FSTYPE'] with allowed return codes [0] (capture=True)
Running command ['sh', '-c', 'rm -f "$1" && umask 0066 && truncate -s 0 "$1" && { chattr +C "$1" || true; } && fallocate -l "${2}M" "$1" && mkswap "$1" || { r=$?; rm -f "$1"; exit $r; }', 'setup_swap', '/tmp/tmpv203or18/target//swap.img', '2048'] with allowed return codes [0] (capture=False)
chattr: Operation not supported while setting flags on /tmp/tmpv203or18/target//swap.img
Setting up swapspace version 1, size = 2 GiB (2147479552 bytes)
no label, UUID=d4cf2a6e-6d62-4cba-9647-7e6ede206d4b
creating swap file '/swap.img' of 2048MB took 0.036 seconds
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/setting-up-swap: SUCCESS: setting up swap
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/apply-networking-config: apply networking config
applying network_config
Checking cloud-init in target [/tmp/tmpv203or18/target] for network configuration passthrough support.
Checking in-target cloud-init for feature: NETWORK_CONFIG_V2
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', '/usr/bin/cloud-init', 'features'] with allowed return codes [0] (capture=True)
cloud-init feature NETWORK_CONFIG_V2 available? True
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.020
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Passing network configuration through to target: /tmp/tmpv203or18/target
Writing network config to etc/cloud/cloud.cfg.d/50-curtin-networking.cfg: /tmp/tmpv203or18/target/etc/cloud/cloud.cfg.d/50-curtin-networking.cfg
Failed to find legacy network conf file /tmp/tmpv203or18/target/etc/network/interfaces.d/eth0.cfg
Attempting to remove ipv6 privacy extensions
Failed to find ipv6 privacy conf file /tmp/tmpv203or18/target/etc/sysctl.d/10-ipv6-privacy.conf
Injecting fix for ipv6 mtu settings: /tmp/tmpv203or18/target/etc/network/if-pre-up.d/mtuipv6
Injecting fix for ipv6 mtu settings: /tmp/tmpv203or18/target/etc/network/if-up.d/mtuipv6
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/apply-networking-config: SUCCESS: apply networking config
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-etc-fstab: writing etc/fstab
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-etc-fstab: SUCCESS: writing etc/fstab
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-multipath: configuring multipath
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/loop0'] with allowed return codes [0] (capture=True)
/dev/loop0 is multipath device? False
/dev/loop0 is multipath device partition? False
Running command ['multipath', '-c', '/dev/loop0'] with allowed return codes [0] (capture=True)
/dev/loop0 is multipath device member? False
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/loop1'] with allowed return codes [0] (capture=True)
/dev/loop1 is multipath device? False
/dev/loop1 is multipath device partition? False
Running command ['multipath', '-c', '/dev/loop1'] with allowed return codes [0] (capture=True)
/dev/loop1 is multipath device member? False
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/loop2'] with allowed return codes [0] (capture=True)
/dev/loop2 is multipath device? False
/dev/loop2 is multipath device partition? False
Running command ['multipath', '-c', '/dev/loop2'] with allowed return codes [0] (capture=True)
/dev/loop2 is multipath device member? False
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/loop3'] with allowed return codes [0] (capture=True)
/dev/loop3 is multipath device? False
/dev/loop3 is multipath device partition? False
Running command ['multipath', '-c', '/dev/loop3'] with allowed return codes [0] (capture=True)
/dev/loop3 is multipath device member? False
Running command ['udevadm', 'info', '--query=property', '--export', '/dev/sda2'] with allowed return codes [0] (capture=True)
/dev/sda2 is multipath device? False
/dev/sda2 is multipath device partition? False
Running command ['multipath', '-c', '/dev/sda2'] with allowed return codes [0] (capture=True)
/dev/sda2 is multipath device member? False
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '--nodeps'] with allowed return codes [0] (capture=True)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/loop0'] with allowed return codes [0] (capture=True)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/loop1'] with allowed return codes [0] (capture=True)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/loop2'] with allowed return codes [0] (capture=True)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/loop3'] with allowed return codes [0] (capture=True)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sda'] with allowed return codes [0] (capture=True)
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID', '/dev/sr0'] with allowed return codes [0] (capture=True)
no devices found to rescan
Running command ['blkid', '-o', 'full'] with allowed return codes [0] (capture=True)
legacy_detect_multipath found blkid info: {'/dev/loop0': {'TYPE': 'squashfs'}, '/dev/loop1': {'TYPE': 'squashfs'}, '/dev/loop2': {'TYPE': 'squashfs'}, '/dev/loop3': {'TYPE': 'squashfs'}, '/dev/sda1': {'PARTUUID': 'af6baa35-de30-41d4-9e71-20889159ce64'}, '/dev/sda2': {'LABEL': 'root', 'UUID': 'e83cada8-a344-4def-9db1-b0d00cbf1840', 'TYPE': 'ext4', 'PARTUUID': 'bf1d48a0-5e16-42bc-910e-cca6e6568eb4'}}
Running command ['lsblk', '--noheadings', '--bytes', '--pairs', '--output=ALIGNMENT,DISC-ALN,DISC-GRAN,DISC-MAX,DISC-ZERO,FSTYPE,GROUP,KNAME,LABEL,LOG-SEC,MAJ:MIN,MIN-IO,MODE,MODEL,MOUNTPOINT,NAME,OPT-IO,OWNER,PHY-SEC,RM,RO,ROTA,RQ-SIZE,SIZE,STATE,TYPE,UUID'] with allowed return codes [0] (capture=True)
target_devs: ['/dev/sda2']
/dev/sda2: e83cada8-a344-4def-9db1-b0d00cbf1840
Multipath detection found: False
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-multipath: SUCCESS: configuring multipath
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/system-upgrade: updating packages on target system
system_upgrade disabled by config.
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/system-upgrade: SUCCESS: updating packages on target system
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/pollinate-user-agent: configuring pollinate user-agent on target
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/pollinate-user-agent: SUCCESS: configuring pollinate user-agent on target
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/updating-initramfs-configuration: updating initramfs configuration
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-divert', '--list'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.006
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Restoring update-initramfs in target for initrd updates.
del_file: removed /tmp/tmpv203or18/target/usr/sbin/update-initramfs
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-divert', '--rename', '--remove', '/usr/sbin/update-initramfs'] with allowed return codes [0] (capture=False)
Removing 'local diversion of /usr/sbin/update-initramfs to /usr/sbin/update-initramfs.curtin-disabled'
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.019
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-divert', '--list'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.021
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'update-initramfs', '-u', '-k', '4.19.0-14-cloud-amd64'] with allowed return codes [0] (capture=False)
update-initramfs: Generating /boot/initrd.img-4.19.0-14-cloud-amd64
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.021
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'update-initramfs', '-c', '-k', '4.19.0-16-amd64'] with allowed return codes [0] (capture=False)
update-initramfs: Generating /boot/initrd.img-4.19.0-16-amd64
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.021
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/updating-initramfs-configuration: SUCCESS: updating initramfs configuration
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-bootloader: configuring target system bootloader
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/install-grub: installing grub to target devices
setup grub on target /tmp/tmpv203or18/target
checking: {'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'}
get_path_to_storage_volume for volume sda({'grub_device': True, 'id': 'sda', 'name': 'sda', 'path': '/dev/sda', 'ptable': 'gpt', 'type': 'disk', 'wipe': 'superblock'})
Running command ['multipath', '-c', '/dev/sda'] with allowed return codes [0] (capture=True)
/dev/sda is multipath device member? False
Running command ['partprobe', '/dev/sda'] with allowed return codes [0, 1] (capture=False)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED udevadm_settle(): 0.060
devsync happy - path /dev/sda now exists
return volume path /dev/sda
install_devices: ['/dev/sda']
Generating grub debconf_selections for devices=['/dev/sda'] uefi=False
Applying grub debconf_selections config:
{'debconf_selections': {'grub': 'grub-pc grub-pc/install_devices multiselect /dev/sda'}}
Applying debconf selections
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'debconf-set-selections'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-query', '--list'] with allowed return codes [0] (capture=True)
The following packages were installed and preseeded, but cannot be unconfigured: ['grub-pc']
installing grub to target=/tmp/tmpv203or18/target devices=['/dev/sda'] [replace_defaults=None]
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg', '--print-architecture'] with allowed return codes [0] (capture=True)
updated /tmp/tmpv203or18/target/etc/default/grub to set: GRUB_CMDLINE_LINUX_DEFAULT="net.ifnames=0 biosdevname=0"
Using grub install command: grub-install
Grub install cmds:
[['dpkg-reconfigure', 'grub-pc'], ['update-grub'], ['grub-install', '/dev/sda']]
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'dpkg-reconfigure', 'grub-pc'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'update-grub'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'grub-install', '/dev/sda'] with allowed return codes [0] (capture=True)
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.057
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/install-grub: SUCCESS: installing grub to target devices
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks/configuring-bootloader: SUCCESS: configuring target system bootloader
finish: cmd-install/stage-curthooks/builtin/cmd-curthooks: SUCCESS: curtin command curthooks
start: cmd-install/stage-hook/builtin/cmd-hook: curtin command hook
Finalizing /tmp/tmpv203or18/target
finish: cmd-install/stage-hook/builtin/cmd-hook: SUCCESS: curtin command hook
start: cmd-install/stage-late/90_create_installer/cmd-in-target: curtin command in-target
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--help'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'sh', '-c', 'sudo useradd bc -g 0'] with allowed return codes [0] (capture=False)
cannot connect to /var/run/nscd/socket
cannot connect to /var/run/nscd/socket
cannot connect to /var/run/nscd/socket
cannot connect to /var/run/nscd/socket
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.019
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
finish: cmd-install/stage-late/90_create_installer/cmd-in-target: SUCCESS: curtin command in-target
start: cmd-install/stage-late/92_set_installer_password/cmd-in-target: curtin command in-target
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--help'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'sh', '-c', "echo 'bc:bc' | sudo chpasswd"] with allowed return codes [0] (capture=False)
cannot connect to /var/run/nscd/socket
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.020
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
finish: cmd-install/stage-late/92_set_installer_password/cmd-in-target: SUCCESS: curtin command in-target
start: cmd-install/stage-late/93_add_sudoer/cmd-in-target: curtin command in-target
Running command ['mount', '--bind', '/dev', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/proc', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/run', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['mount', '--bind', '/sys', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['unshare', '--help'] with allowed return codes [0] (capture=True)
Running command ['unshare', '--fork', '--pid', '--', 'chroot', '/tmp/tmpv203or18/target', 'sh', '-c', 'sudo usermod -aG sudo bc'] with allowed return codes [0] (capture=False)
cannot connect to /var/run/nscd/socket
cannot connect to /var/run/nscd/socket
cannot connect to /var/run/nscd/socket
cannot connect to /var/run/nscd/socket
Running command ['udevadm', 'settle'] with allowed return codes [0] (capture=False)
TIMED subp(['udevadm', 'settle']): 0.019
Running command ['umount', '/tmp/tmpv203or18/target/sys'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/run'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/proc'] with allowed return codes [0] (capture=False)
Running command ['umount', '/tmp/tmpv203or18/target/dev'] with allowed return codes [0] (capture=False)
finish: cmd-install/stage-late/93_add_sudoer/cmd-in-target: SUCCESS: curtin command in-target
--2021-05-02 23:02:33--  http://192.168.50.10:5248/MAAS/metadata/latest/by-id/7s6r6d/
Connecting to 192.168.50.10:5248... connected.
HTTP request sent, awaiting response... 200 OK
Length: 2 [text/plain]
Saving to: ‘/dev/null’

     0K                                                       100%  487K=0s

2021-05-02 23:02:33 (487 KB/s) - ‘/dev/null’ saved [2/2]

curtin: Installation finished.

ltrager · 3 May 2021 22:03

I think the bug would be in cloud-init. I would open a bug at https://bugs.launchpad.net/cloud-init/+filebug

The reason there is nothing in the MAAS log is Curtin thinks its behaving as its supposed to. It doesn’t report it didn’t write cloud-config because its assuming thats what you want.

cbnorman · 4 May 2021 09:13

Hi @ltrager

I’ve filed a bug with cloud-init as suggested. As the write_files i manually configured do work, do you think i could manually configure the datasource in the mean time?

billwear · 4 May 2021 14:12

@cbnorman, that’s a really good question; i’d like to know that answer as well.

cbnorman · 4 May 2021 14:15

interestingly i just replaced

apt:
  preserve_sources_list: true

with

apt:
  sources_list: | # written by curtin custom template
    deb http://deb.debian.org/debian buster main
    deb-src http://deb.debian.org/debian buster main
    deb http://security.debian.org/debian-security buster/updates main
    deb-src http://security.debian.org/debian-security buster/updates main

again it deploys fine but no maas datasources are applied. so it fails on final boot?

cbnorman · 5 May 2021 09:23

i see this in the curtin logs

Configuring target system for distro: debian osfamily: debian
start: cmd-install/stage-curthooks/builtin/cmd-curthooks/writing-apt-config: configuring apt configuring apt
Transferred {'grub2': 'grub2   grub2/update_nvram  boolean false', 'maas': 'cloud-init   cloud-init/datasources  multiselect MAAS\ncloud-init   cloud-init/maas-metadata-url  string http://192.168.50.10:5248/MAAS/metadata/\ncloud-init   cloud-init/maas-metadata-credentials  string oauth_consumer_key=dpvF8J6ncpH3mkuehd&oauth_token_key=3B3cdJWFdFk2L7S6Qw&oauth_token_secret=fb84HsCZPDHN39M9tUtuWNycQKbRDG4b\ncloud-init   cloud-init/local-cloud-config  string manage_etc_hosts: true\\nmanual_cache_clean: true\\nreporting:\\n  maas:\\n    consumer_key: dpvF8J6ncpH3mkuehd\\n    endpoint: http://192.168.50.10:5248/MAAS/metadata/status/qkak7f\\n    token_key: 3B3cdJWFdFk2L7S6Qw\\n    token_secret: fb84HsCZPDHN39M9tUtuWNycQKbRDG4b\\n    type: webhook\\n\n'} into new format: {'preserve_sources_list': False, 'proxy': 'http://192.168.50.10:8000/', 'sources_list': 'deb http://deb.debian.org/debian buster main\ndeb-src http://deb.debian.org/debian buster main\ndeb http://security.debian.org/debian-security buster/updates main\ndeb-src http://security.debian.org/debian-security buster/updates main\n', 'debconf_selections': {'grub2': 'grub2   grub2/update_nvram  boolean false', 'maas': 'cloud-init   cloud-init/datasources  multiselect MAAS\ncloud-init   cloud-init/maas-metadata-url  string http://192.168.50.10:5248/MAAS/metadata/\ncloud-init   cloud-init/maas-metadata-credentials  string oauth_consumer_key=dpvF8J6ncpH3mkuehd&oauth_token_key=3B3cdJWFdFk2L7S6Qw&oauth_token_secret=fb84HsCZPDHN39M9tUtuWNycQKbRDG4b\ncloud-init   cloud-init/local-cloud-config  string manage_etc_hosts: true\\nmanual_cache_clean: true\\nreporting:\\n  maas:\\n    consumer_key: dpvF8J6ncpH3mkuehd\\n    endpoint: http://192.168.50.10:5248/MAAS/metadata/status/qkak7f\\n    token_key: 3B3cdJWFdFk2L7S6Qw\\n    token_secret: fb84HsCZPDHN39M9tUtuWNycQKbRDG4b\\n    type: webhook\\n\n'}}
curthooks handling apt to target /tmp/tmp1ccj6b03/target with config {'preserve_sources_list': False, 'proxy': 'http://192.168.50.10:8000/', 'sources_list': 'deb http://deb.debian.org/debian buster main\ndeb-src http://deb.debian.org/debian buster main\ndeb http://security.debian.org/debian-security buster/updates main\ndeb-src http://security.debian.org/debian-security buster/updates main\n', 'debconf_selections': {'grub2': 'grub2   grub2/update_nvram  boolean false', 'maas': 'cloud-init   cloud-init/datasources  multiselect MAAS\ncloud-init   cloud-init/maas-metadata-url  string http://192.168.50.10:5248/MAAS/metadata/\ncloud-init   cloud-init/maas-metadata-credentials  string oauth_consumer_key=dpvF8J6ncpH3mkuehd&oauth_token_key=3B3cdJWFdFk2L7S6Qw&oauth_token_secret=fb84HsCZPDHN39M9tUtuWNycQKbRDG4b\ncloud-init   cloud-init/local-cloud-config  string manage_etc_hosts: true\\nmanual_cache_clean: true\\nreporting:\\n  maas:\\n    consumer_key: dpvF8J6ncpH3mkuehd\\n    endpoint: http://192.168.50.10:5248/MAAS/metadata/status/qkak7f\\n    token_key: 3B3cdJWFdFk2L7S6Qw\\n    token_secret: fb84HsCZPDHN39M9tUtuWNycQKbRDG4b\\n    type: webhook\\n\n'}}

so the datasource is available but doesnt seem to be written to the target. the network settings seem to be coppied fine

Writing network config to etc/cloud/cloud.cfg.d/50-curtin-networking.cfg: /tmp/tmp1ccj6b03/target/etc/cloud/cloud.cfg.d/50-curtin-networking.cfg

I don’t really think this is a bug with cloud-init and more likely an issue with curtin or MAAS itself. Do you know how i can get more debug logs?