2021-08-22 12:55:31 INFO Starting vmdb2 version 0.22
2021-08-22 12:55:31 INFO Load spec file uefi-qemu-with-virtual.vmdb
2021-08-22 12:55:31 INFO Exec: ['dpkg', '--print-architecture']
2021-08-22 12:55:31 DEBUG STDOUT: amd64

2021-08-22 12:55:31 DEBUG STDERR: 
2021-08-22 12:55:31 INFO Running step: {'mkimg': 'test.img', 'size': '4G'}
2021-08-22 12:55:31 INFO Calling <bound method MkimgStepRunner.run of <mkimg_plugin.MkimgStepRunner object at 0x7f64e4603c70>>
2021-08-22 12:55:31 INFO Exec: ['qemu-img', 'create', '-f', 'raw', 'test.img', '4G']
2021-08-22 12:55:31 DEBUG STDOUT: Formatting 'test.img', fmt=raw size=4294967296

2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkimg_plugin.MkimgStepRunner object at 0x7f64e4603c70>>
2021-08-22 12:55:32 INFO Running step: {'mklabel': 'gpt', 'device': 'test.img'}
2021-08-22 12:55:32 INFO Calling <bound method MklabelStepRunner.run of <mklabel_plugin.MklabelStepRunner object at 0x7f64e4603ca0>>
2021-08-22 12:55:32 INFO Exec: ['parted', '-s', 'test.img', 'mklabel', 'gpt']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mklabel_plugin.MklabelStepRunner object at 0x7f64e4603ca0>>
2021-08-22 12:55:32 INFO Running step: {'mkpart': 'primary', 'device': 'test.img', 'start': '0%', 'end': '1G', 'tag': 'efi'}
2021-08-22 12:55:32 INFO Calling <bound method MkpartStepRunner.run of <mkpart_plugin.MkpartStepRunner object at 0x7f64e4603cd0>>
2021-08-22 12:55:32 INFO Exec: ['parted', '-m', '/var/tmp/test.img', 'print']
2021-08-22 12:55:32 DEBUG STDOUT: BYT;
/var/tmp/test.img:4295MB:file:512:512:gpt::;

2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['parted', '-s', '/var/tmp/test.img', '--', 'mkpart', 'primary', 'ext2', '0%', '1G']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['parted', '-m', '/var/tmp/test.img', 'print']
2021-08-22 12:55:32 DEBUG STDOUT: BYT;
/var/tmp/test.img:4295MB:file:512:512:gpt::;
1:1049kB:1000MB:999MB::primary:;

2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkpart_plugin.MkpartStepRunner object at 0x7f64e4603cd0>>
2021-08-22 12:55:32 INFO Running step: {'mkpart': 'primary', 'device': 'test.img', 'start': '1G', 'end': '100%', 'tag': '/'}
2021-08-22 12:55:32 INFO Calling <bound method MkpartStepRunner.run of <mkpart_plugin.MkpartStepRunner object at 0x7f64e4603cd0>>
2021-08-22 12:55:32 INFO Exec: ['parted', '-m', '/var/tmp/test.img', 'print']
2021-08-22 12:55:32 DEBUG STDOUT: BYT;
/var/tmp/test.img:4295MB:file:512:512:gpt::;
1:1049kB:1000MB:999MB::primary:;

2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['parted', '-s', '/var/tmp/test.img', '--', 'mkpart', 'primary', 'ext2', '1G', '100%']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['parted', '-m', '/var/tmp/test.img', 'print']
2021-08-22 12:55:32 DEBUG STDOUT: BYT;
/var/tmp/test.img:4295MB:file:512:512:gpt::;
1:1049kB:1000MB:999MB::primary:;
2:1000MB:4294MB:3294MB::primary:;

2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkpart_plugin.MkpartStepRunner object at 0x7f64e4603cd0>>
2021-08-22 12:55:32 INFO Running step: {'kpartx': 'test.img'}
2021-08-22 12:55:32 INFO Calling <bound method KpartxStepRunner.run of <kpartx_plugin.KpartxStepRunner object at 0x7f64e4603bb0>>
2021-08-22 12:55:32 INFO Exec: ['kpartx', '-asv', 'test.img']
2021-08-22 12:55:32 DEBUG STDOUT: add map loop0p1 (254:0): 0 1951744 linear 7:0 2048
add map loop0p2 (254:1): 0 6432768 linear 7:0 1953792

2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO remembering /dev/mapper/loop0p1 as efi
2021-08-22 12:55:32 INFO remembering /dev/mapper/loop0p2 as /
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <kpartx_plugin.KpartxStepRunner object at 0x7f64e4603bb0>>
2021-08-22 12:55:32 INFO Running step: {'mkfs': 'vfat', 'partition': 'efi'}
2021-08-22 12:55:32 INFO Calling <bound method MkfsStepRunner.run of <mkfs_plugin.MkfsStepRunner object at 0x7f64e4603c40>>
2021-08-22 12:55:32 INFO Exec: ['/sbin/mkfs', '-t', 'vfat', '/dev/mapper/loop0p1']
2021-08-22 12:55:32 DEBUG STDOUT: mkfs.fat 4.2 (2021-01-31)

2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkfs_plugin.MkfsStepRunner object at 0x7f64e4603c40>>
2021-08-22 12:55:32 INFO Running step: {'mkfs': 'ext4', 'partition': '/'}
2021-08-22 12:55:32 INFO Calling <bound method MkfsStepRunner.run of <mkfs_plugin.MkfsStepRunner object at 0x7f64e4603c40>>
2021-08-22 12:55:32 INFO Exec: ['/sbin/mkfs', '-t', 'ext4', '/dev/mapper/loop0p2']
2021-08-22 12:55:32 DEBUG STDOUT: Discarding device blocks:   4096/804096             done                            
Creating filesystem with 804096 4k blocks and 201200 inodes
Filesystem UUID: ad16a7e6-3014-4e78-8230-0b60ec268e30
Superblock backups stored on blocks: 
	32768, 98304, 163840, 229376, 294912

Allocating group tables:  0/25     done                            
Writing inode tables:  0/25     done                            
Creating journal (16384 blocks): done
Writing superblocks and filesystem accounting information:  0/25     done


2021-08-22 12:55:32 DEBUG STDERR: mke2fs 1.46.2 (28-Feb-2021)

2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkfs_plugin.MkfsStepRunner object at 0x7f64e4603c40>>
2021-08-22 12:55:32 INFO Running step: {'mount': '/'}
2021-08-22 12:55:32 INFO Calling <bound method MountStepRunner.run of <mount_plugin.MountStepRunner object at 0x7f64e4603d00>>
2021-08-22 12:55:32 INFO Exec: ['mount', '/dev/mapper/loop0p2', '/tmp/tmpt30k175g']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mount_plugin.MountStepRunner object at 0x7f64e4603d00>>
2021-08-22 12:55:32 INFO Running step: {'virtual-filesystems': '/'}
2021-08-22 12:55:32 INFO Calling <bound method VirtualFilesystemMountStepRunner.run of <virtualfs_plugin.VirtualFilesystemMountStepRunner object at 0x7f64e4603e20>>
2021-08-22 12:55:32 INFO Exec: ['mount', '-t', 'proc', 'none', '/tmp/tmpt30k175g/.//proc']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['mount', '-t', 'devtmpfs', 'none', '/tmp/tmpt30k175g/.//dev']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['mount', '-t', 'devpts', 'none', '/tmp/tmpt30k175g/.//dev/pts']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['mount', '-t', 'tmpfs', 'none', '/tmp/tmpt30k175g/.//dev/shm']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['mount', '-t', 'tmpfs', 'none', '/tmp/tmpt30k175g/.//run']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['mount', '-t', 'tmpfs', 'none', '/tmp/tmpt30k175g/.//run/lock']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 INFO Exec: ['mount', '-t', 'sysfs', 'none', '/tmp/tmpt30k175g/.//sys']
2021-08-22 12:55:32 DEBUG STDOUT: 
2021-08-22 12:55:32 DEBUG STDERR: 
2021-08-22 12:55:32 DEBUG mounted virtuals: ['/tmp/tmpt30k175g/.//proc', '/tmp/tmpt30k175g/.//dev', '/tmp/tmpt30k175g/.//dev/pts', '/tmp/tmpt30k175g/.//dev/shm', '/tmp/tmpt30k175g/.//run', '/tmp/tmpt30k175g/.//run/lock', '/tmp/tmpt30k175g/.//sys']
2021-08-22 12:55:32 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <virtualfs_plugin.VirtualFilesystemMountStepRunner object at 0x7f64e4603e20>>
2021-08-22 12:55:32 INFO Running step: {'qemu-debootstrap': 'buster', 'arch': 'i386', 'mirror': 'http://deb.debian.org/debian', 'target': '/'}
2021-08-22 12:55:32 INFO Calling <bound method QemuDebootstrapStepRunner.run of <qemudebootstrap_plugin.QemuDebootstrapStepRunner object at 0x7f64e4603d30>>
2021-08-22 12:55:32 INFO Exec: ['qemu-debootstrap', '--arch', 'i386', '--variant', '-', '--components', 'main', 'buster', '/tmp/tmpt30k175g', 'http://deb.debian.org/debian']
2021-08-22 12:56:36 DEBUG STDOUT: I: Target architecture can be executed
I: Retrieving InRelease 
I: Checking Release signature
I: Valid Release signature (key id 6D33866EDD8FFA41C0143AEDDCC9EFBF77E11517)
I: Retrieving Packages 
I: Validating Packages 
I: Resolving dependencies of required packages...
I: Resolving dependencies of base packages...
I: Checking component main on http://deb.debian.org/debian...
I: Retrieving libacl1 2.2.53-4
I: Validating libacl1 2.2.53-4
I: Retrieving adduser 3.118
I: Validating adduser 3.118
I: Retrieving libapparmor1 2.13.2-10
I: Validating libapparmor1 2.13.2-10
I: Retrieving apt 1.8.2.3
I: Validating apt 1.8.2.3
I: Retrieving apt-utils 1.8.2.3
I: Validating apt-utils 1.8.2.3
I: Retrieving libapt-inst2.0 1.8.2.3
I: Validating libapt-inst2.0 1.8.2.3
I: Retrieving libapt-pkg5.0 1.8.2.3
I: Validating libapt-pkg5.0 1.8.2.3
I: Retrieving libargon2-1 0~20171227-0.2
I: Validating libargon2-1 0~20171227-0.2
I: Retrieving libattr1 1:2.4.48-4
I: Validating libattr1 1:2.4.48-4
I: Retrieving libaudit-common 1:2.8.4-3
I: Validating libaudit-common 1:2.8.4-3
I: Retrieving libaudit1 1:2.8.4-3
I: Validating libaudit1 1:2.8.4-3
I: Retrieving base-files 10.3+deb10u10
I: Validating base-files 10.3+deb10u10
I: Retrieving base-passwd 3.5.46
I: Validating base-passwd 3.5.46
I: Retrieving bash 5.0-4
I: Validating bash 5.0-4
I: Retrieving libdns-export1104 1:9.11.5.P4+dfsg-5.1+deb10u5
I: Validating libdns-export1104 1:9.11.5.P4+dfsg-5.1+deb10u5
I: Retrieving libisc-export1100 1:9.11.5.P4+dfsg-5.1+deb10u5
I: Validating libisc-export1100 1:9.11.5.P4+dfsg-5.1+deb10u5
I: Retrieving bsdmainutils 11.1.2+b1
I: Validating bsdmainutils 11.1.2+b1
I: Retrieving libbz2-1.0 1.0.6-9.2~deb10u1
I: Validating libbz2-1.0 1.0.6-9.2~deb10u1
I: Retrieving libdebconfclient0 0.249
I: Validating libdebconfclient0 0.249
I: Retrieving coreutils 8.30-3
I: Validating coreutils 8.30-3
I: Retrieving cpio 2.12+dfsg-9
I: Validating cpio 2.12+dfsg-9
I: Retrieving cron 3.0pl1-134+deb10u1
I: Validating cron 3.0pl1-134+deb10u1
I: Retrieving libcryptsetup12 2:2.1.0-5+deb10u2
I: Validating libcryptsetup12 2:2.1.0-5+deb10u2
I: Retrieving dash 0.5.10.2-5
I: Validating dash 0.5.10.2-5
I: Retrieving libdb5.3 5.3.28+dfsg1-0.5
I: Validating libdb5.3 5.3.28+dfsg1-0.5
I: Retrieving debconf 1.5.71
I: Validating debconf 1.5.71
I: Retrieving debconf-i18n 1.5.71
I: Validating debconf-i18n 1.5.71
I: Retrieving debian-archive-keyring 2019.1+deb10u1
I: Validating debian-archive-keyring 2019.1+deb10u1
I: Retrieving debianutils 4.8.6.1
I: Validating debianutils 4.8.6.1
I: Retrieving diffutils 1:3.7-3
I: Validating diffutils 1:3.7-3
I: Retrieving dmidecode 3.2-1
I: Validating dmidecode 3.2-1
I: Retrieving dpkg 1.19.7
I: Validating dpkg 1.19.7
I: Retrieving e2fsprogs 1.44.5-1+deb10u3
I: Validating e2fsprogs 1.44.5-1+deb10u3
I: Retrieving libcom-err2 1.44.5-1+deb10u3
I: Validating libcom-err2 1.44.5-1+deb10u3
I: Retrieving libext2fs2 1.44.5-1+deb10u3
I: Validating libext2fs2 1.44.5-1+deb10u3
I: Retrieving libss2 1.44.5-1+deb10u3
I: Validating libss2 1.44.5-1+deb10u3
I: Retrieving libelf1 0.176-1.1
I: Validating libelf1 0.176-1.1
I: Retrieving findutils 4.6.0+git+20190209-2
I: Validating findutils 4.6.0+git+20190209-2
I: Retrieving gcc-8-base 8.3.0-6
I: Validating gcc-8-base 8.3.0-6
I: Retrieving libgcc1 1:8.3.0-6
I: Validating libgcc1 1:8.3.0-6
I: Retrieving libstdc++6 8.3.0-6
I: Validating libstdc++6 8.3.0-6
I: Retrieving gdbm-l10n 1.18.1-4
I: Validating gdbm-l10n 1.18.1-4
I: Retrieving libc-bin 2.28-10
I: Validating libc-bin 2.28-10
I: Retrieving libc6 2.28-10
I: Validating libc6 2.28-10
I: Retrieving libgmp10 2:6.1.2+dfsg-4
I: Validating libgmp10 2:6.1.2+dfsg-4
I: Retrieving gpgv 2.2.12-1+deb10u1
I: Validating gpgv 2.2.12-1+deb10u1
I: Retrieving libgnutls30 3.6.7-4+deb10u7
I: Validating libgnutls30 3.6.7-4+deb10u7
I: Retrieving grep 3.3-1
I: Validating grep 3.3-1
I: Retrieving gzip 1.9-3
I: Validating gzip 1.9-3
I: Retrieving hostname 3.21
I: Validating hostname 3.21
I: Retrieving ifupdown 0.8.35
I: Validating ifupdown 0.8.35
I: Retrieving init 1.56+nmu1
I: Validating init 1.56+nmu1
I: Retrieving init-system-helpers 1.56+nmu1
I: Validating init-system-helpers 1.56+nmu1
I: Retrieving iproute2 4.20.0-2+deb10u1
I: Validating iproute2 4.20.0-2+deb10u1
I: Retrieving iptables 1.8.2-4
I: Validating iptables 1.8.2-4
I: Retrieving libip4tc0 1.8.2-4
I: Validating libip4tc0 1.8.2-4
I: Retrieving libip6tc0 1.8.2-4
I: Validating libip6tc0 1.8.2-4
I: Retrieving libiptc0 1.8.2-4
I: Validating libiptc0 1.8.2-4
I: Retrieving libxtables12 1.8.2-4
I: Validating libxtables12 1.8.2-4
I: Retrieving iputils-ping 3:20180629-2+deb10u2
I: Validating iputils-ping 3:20180629-2+deb10u2
I: Retrieving isc-dhcp-client 4.4.1-2+deb10u1
I: Validating isc-dhcp-client 4.4.1-2+deb10u1
I: Retrieving isc-dhcp-common 4.4.1-2+deb10u1
I: Validating isc-dhcp-common 4.4.1-2+deb10u1
I: Retrieving libjson-c3 0.12.1+ds-2+deb10u1
I: Validating libjson-c3 0.12.1+ds-2+deb10u1
I: Retrieving kmod 26-1
I: Validating kmod 26-1
I: Retrieving libkmod2 26-1
I: Validating libkmod2 26-1
I: Retrieving less 487-0.1+b1
I: Validating less 487-0.1+b1
I: Retrieving libbsd0 0.9.1-2+deb10u1
I: Validating libbsd0 0.9.1-2+deb10u1
I: Retrieving libcap-ng0 0.7.9-2
I: Validating libcap-ng0 0.7.9-2
I: Retrieving libcap2 1:2.25-2
I: Validating libcap2 1:2.25-2
I: Retrieving libcap2-bin 1:2.25-2
I: Validating libcap2-bin 1:2.25-2
I: Retrieving libestr0 0.1.10-2.1
I: Validating libestr0 0.1.10-2.1
I: Retrieving libfastjson4 0.99.8-2
I: Validating libfastjson4 0.99.8-2
I: Retrieving libffi6 3.2.1-9
I: Validating libffi6 3.2.1-9
I: Retrieving libgcrypt20 1.8.4-5+deb10u1
I: Validating libgcrypt20 1.8.4-5+deb10u1
I: Retrieving libgpg-error0 1.35-1
I: Validating libgpg-error0 1.35-1
I: Retrieving libidn11 1.33-2.2
I: Validating libidn11 1.33-2.2
I: Retrieving libidn2-0 2.0.5-1+deb10u1
I: Validating libidn2-0 2.0.5-1+deb10u1
I: Retrieving liblocale-gettext-perl 1.07-3+b4
I: Validating liblocale-gettext-perl 1.07-3+b4
I: Retrieving liblognorm5 2.0.5-1
I: Validating liblognorm5 2.0.5-1
I: Retrieving libmnl0 1.0.4-2
I: Validating libmnl0 1.0.4-2
I: Retrieving libnetfilter-conntrack3 1.0.7-1
I: Validating libnetfilter-conntrack3 1.0.7-1
I: Retrieving libnfnetlink0 1.0.1-3+b1
I: Validating libnfnetlink0 1.0.1-3+b1
I: Retrieving libnftnl11 1.1.2-2
I: Validating libnftnl11 1.1.2-2
I: Retrieving libseccomp2 2.3.3-4
I: Validating libseccomp2 2.3.3-4
I: Retrieving libselinux1 2.8-1+b1
I: Validating libselinux1 2.8-1+b1
I: Retrieving libsemanage-common 2.8-2
I: Validating libsemanage-common 2.8-2
I: Retrieving libsemanage1 2.8-2
I: Validating libsemanage1 2.8-2
I: Retrieving libsepol1 2.8-1
I: Validating libsepol1 2.8-1
I: Retrieving libtasn1-6 4.13-3
I: Validating libtasn1-6 4.13-3
I: Retrieving libtext-charwidth-perl 0.04-7.1+b1
I: Validating libtext-charwidth-perl 0.04-7.1+b1
I: Retrieving libtext-iconv-perl 1.7-5+b7
I: Validating libtext-iconv-perl 1.7-5+b7
I: Retrieving libtext-wrapi18n-perl 0.06-7.1
I: Validating libtext-wrapi18n-perl 0.06-7.1
I: Retrieving libunistring2 0.9.10-1
I: Validating libunistring2 0.9.10-1
I: Retrieving libzstd1 1.3.8+dfsg-3+deb10u2
I: Validating libzstd1 1.3.8+dfsg-3+deb10u2
I: Retrieving logrotate 3.14.0-4
I: Validating logrotate 3.14.0-4
I: Retrieving lsb-base 10.2019051400
I: Validating lsb-base 10.2019051400
I: Retrieving dmsetup 2:1.02.155-3
I: Validating dmsetup 2:1.02.155-3
I: Retrieving libdevmapper1.02.1 2:1.02.155-3
I: Validating libdevmapper1.02.1 2:1.02.155-3
I: Retrieving liblz4-1 1.8.3-1+deb10u1
I: Validating liblz4-1 1.8.3-1+deb10u1
I: Retrieving mawk 1.3.3-17+b3
I: Validating mawk 1.3.3-17+b3
I: Retrieving nano 3.2-3
I: Validating nano 3.2-3
I: Retrieving libncurses6 6.1+20181013-2+deb10u2
I: Validating libncurses6 6.1+20181013-2+deb10u2
I: Retrieving libncursesw6 6.1+20181013-2+deb10u2
I: Validating libncursesw6 6.1+20181013-2+deb10u2
I: Retrieving libtinfo6 6.1+20181013-2+deb10u2
I: Validating libtinfo6 6.1+20181013-2+deb10u2
I: Retrieving ncurses-base 6.1+20181013-2+deb10u2
I: Validating ncurses-base 6.1+20181013-2+deb10u2
I: Retrieving ncurses-bin 6.1+20181013-2+deb10u2
I: Validating ncurses-bin 6.1+20181013-2+deb10u2
I: Retrieving netbase 5.6
I: Validating netbase 5.6
I: Retrieving libhogweed4 3.4.1-1
W: Couldn't download package libhogweed4 (ver 3.4.1-1 arch i386) at http://deb.debian.org/debian/pool/main/n/nettle/libhogweed4_3.4.1-1_i386.deb
I: Retrieving libnettle6 3.4.1-1
I: Validating libnettle6 3.4.1-1
I: Retrieving libnewt0.52 0.52.20-8
I: Validating libnewt0.52 0.52.20-8
I: Retrieving whiptail 0.52.20-8
I: Validating whiptail 0.52.20-8
I: Retrieving libssl1.1 1.1.1d-0+deb10u6
I: Validating libssl1.1 1.1.1d-0+deb10u6
I: Retrieving libp11-kit0 0.23.15-2+deb10u1
I: Validating libp11-kit0 0.23.15-2+deb10u1
I: Retrieving libpam-modules 1.3.1-5
I: Validating libpam-modules 1.3.1-5
I: Retrieving libpam-modules-bin 1.3.1-5
I: Validating libpam-modules-bin 1.3.1-5
I: Retrieving libpam-runtime 1.3.1-5
I: Validating libpam-runtime 1.3.1-5
I: Retrieving libpam0g 1.3.1-5
I: Validating libpam0g 1.3.1-5
I: Retrieving libpcre3 2:8.39-12
I: Validating libpcre3 2:8.39-12
I: Retrieving perl-base 5.28.1-6+deb10u1
I: Validating perl-base 5.28.1-6+deb10u1
I: Retrieving libpopt0 1.16-12
I: Validating libpopt0 1.16-12
I: Retrieving libprocps7 2:3.3.15-2
I: Validating libprocps7 2:3.3.15-2
I: Retrieving procps 2:3.3.15-2
I: Validating procps 2:3.3.15-2
I: Retrieving readline-common 7.0-5
I: Validating readline-common 7.0-5
I: Retrieving rsyslog 8.1901.0-1
I: Validating rsyslog 8.1901.0-1
I: Retrieving sed 4.7-1
I: Validating sed 4.7-1
I: Retrieving sensible-utils 0.0.12
I: Validating sensible-utils 0.0.12
I: Retrieving login 1:4.5-1.1
I: Validating login 1:4.5-1.1
I: Retrieving passwd 1:4.5-1.1
I: Validating passwd 1:4.5-1.1
I: Retrieving libslang2 2.3.2-2
I: Validating libslang2 2.3.2-2
I: Retrieving libsystemd0 241-7~deb10u7
I: Validating libsystemd0 241-7~deb10u7
I: Retrieving libudev1 241-7~deb10u7
I: Validating libudev1 241-7~deb10u7
I: Retrieving systemd 241-7~deb10u7
I: Validating systemd 241-7~deb10u7
I: Retrieving systemd-sysv 241-7~deb10u7
I: Validating systemd-sysv 241-7~deb10u7
I: Retrieving udev 241-7~deb10u7
I: Validating udev 241-7~deb10u7
I: Retrieving sysvinit-utils 2.93-8
I: Validating sysvinit-utils 2.93-8
I: Retrieving tar 1.30+dfsg-6
I: Validating tar 1.30+dfsg-6
I: Retrieving tasksel 3.53
I: Validating tasksel 3.53
I: Retrieving tasksel-data 3.53
I: Validating tasksel-data 3.53
I: Retrieving tzdata 2021a-0+deb10u1
I: Validating tzdata 2021a-0+deb10u1
I: Retrieving bsdutils 1:2.33.1-0.1
I: Validating bsdutils 1:2.33.1-0.1
I: Retrieving fdisk 2.33.1-0.1
I: Validating fdisk 2.33.1-0.1
I: Retrieving libblkid1 2.33.1-0.1
I: Validating libblkid1 2.33.1-0.1
I: Retrieving libfdisk1 2.33.1-0.1
I: Validating libfdisk1 2.33.1-0.1
I: Retrieving libmount1 2.33.1-0.1
I: Validating libmount1 2.33.1-0.1
I: Retrieving libsmartcols1 2.33.1-0.1
I: Validating libsmartcols1 2.33.1-0.1
I: Retrieving libuuid1 2.33.1-0.1
I: Validating libuuid1 2.33.1-0.1
I: Retrieving mount 2.33.1-0.1
I: Validating mount 2.33.1-0.1
I: Retrieving util-linux 2.33.1-0.1
I: Validating util-linux 2.33.1-0.1
I: Retrieving vim-common 2:8.1.0875-5
I: Validating vim-common 2:8.1.0875-5
I: Retrieving vim-tiny 2:8.1.0875-5
I: Validating vim-tiny 2:8.1.0875-5
I: Retrieving xxd 2:8.1.0875-5
I: Validating xxd 2:8.1.0875-5
I: Retrieving liblzma5 5.2.4-1
I: Validating liblzma5 5.2.4-1
I: Retrieving zlib1g 1:1.2.11.dfsg-1
I: Validating zlib1g 1:1.2.11.dfsg-1
E: Couldn't download packages: libhogweed4

2021-08-22 12:56:36 DEBUG STDERR: W: qemu-debootstrap is deprecated. Please use regular debootstrap directly
I: Running command: debootstrap --arch i386 --variant - --components main buster /tmp/tmpt30k175g http://deb.debian.org/debian

2021-08-22 12:56:36 ERROR Program failed: 1
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/vmdb/app.py", line 220, in run_steps_helper
    method(values, settings, state)
  File "/usr/lib/python3/dist-packages/vmdb/plugins/qemudebootstrap_plugin.py", line 72, in run
    vmdb.runcmd(
  File "/usr/lib/python3/dist-packages/vmdb/runcmd.py", line 58, in runcmd
    raise RuncmdError("Program failed: {}".format(p.returncode))
vmdb.runcmd.RuncmdError: Program failed: 1
2021-08-22 12:56:36 ERROR RuncmdError('Program failed: 1')
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/vmdb/app.py", line 220, in run_steps_helper
    method(values, settings, state)
  File "/usr/lib/python3/dist-packages/vmdb/plugins/qemudebootstrap_plugin.py", line 72, in run
    vmdb.runcmd(
  File "/usr/lib/python3/dist-packages/vmdb/runcmd.py", line 58, in runcmd
    raise RuncmdError("Program failed: {}".format(p.returncode))
vmdb.runcmd.RuncmdError: Program failed: 1
2021-08-22 12:56:36 INFO Something went wrong, cleaning up!
2021-08-22 12:56:36 INFO Running teardown: {'qemu-debootstrap': 'buster', 'arch': 'i386', 'mirror': 'http://deb.debian.org/debian', 'target': '/'}
2021-08-22 12:56:36 INFO Calling <bound method StepRunnerInterface.teardown of <qemudebootstrap_plugin.QemuDebootstrapStepRunner object at 0x7f64e4603d30>>
2021-08-22 12:56:36 INFO Running teardown: {'virtual-filesystems': '/'}
2021-08-22 12:56:36 INFO Calling <bound method VirtualFilesystemMountStepRunner.teardown of <virtualfs_plugin.VirtualFilesystemMountStepRunner object at 0x7f64e4603e20>>
2021-08-22 12:56:36 DEBUG unmounting virtuals: ['/tmp/tmpt30k175g/.//proc', '/tmp/tmpt30k175g/.//dev', '/tmp/tmpt30k175g/.//dev/pts', '/tmp/tmpt30k175g/.//dev/shm', '/tmp/tmpt30k175g/.//run', '/tmp/tmpt30k175g/.//run/lock', '/tmp/tmpt30k175g/.//sys']
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g/.//sys and everything on top of it
2021-08-22 12:56:36 WARNING Not mounted: /tmp/tmpt30k175g/.//sys
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g/.//run/lock and everything on top of it
2021-08-22 12:56:36 WARNING Not mounted: /tmp/tmpt30k175g/.//run/lock
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g/.//run and everything on top of it
2021-08-22 12:56:36 WARNING Not mounted: /tmp/tmpt30k175g/.//run
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g/.//dev/shm and everything on top of it
2021-08-22 12:56:36 WARNING Not mounted: /tmp/tmpt30k175g/.//dev/shm
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g/.//dev/pts and everything on top of it
2021-08-22 12:56:36 WARNING Not mounted: /tmp/tmpt30k175g/.//dev/pts
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g/.//dev and everything on top of it
2021-08-22 12:56:36 WARNING Not mounted: /tmp/tmpt30k175g/.//dev
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g/.//proc and everything on top of it
2021-08-22 12:56:36 WARNING Not mounted: /tmp/tmpt30k175g/.//proc
2021-08-22 12:56:36 INFO Running teardown: {'mount': '/'}
2021-08-22 12:56:36 INFO Calling <bound method MountStepRunner.teardown of <mount_plugin.MountStepRunner object at 0x7f64e4603d00>>
2021-08-22 12:56:36 DEBUG Unmounting /tmp/tmpt30k175g and everything on top of it
2021-08-22 12:56:36 DEBUG Finished unmounting /tmp/tmpt30k175g
2021-08-22 12:56:36 INFO Running teardown: {'mkfs': 'ext4', 'partition': '/'}
2021-08-22 12:56:36 INFO Calling <bound method StepRunnerInterface.teardown of <mkfs_plugin.MkfsStepRunner object at 0x7f64e4603c40>>
2021-08-22 12:56:36 INFO Running teardown: {'mkfs': 'vfat', 'partition': 'efi'}
2021-08-22 12:56:36 INFO Calling <bound method StepRunnerInterface.teardown of <mkfs_plugin.MkfsStepRunner object at 0x7f64e4603c40>>
2021-08-22 12:56:36 INFO Running teardown: {'kpartx': 'test.img'}
2021-08-22 12:56:36 INFO Calling <bound method KpartxStepRunner.teardown of <kpartx_plugin.KpartxStepRunner object at 0x7f64e4603bb0>>
2021-08-22 12:56:36 INFO Exec: ['kpartx', '-dsv', 'test.img']
2021-08-22 12:56:37 DEBUG STDOUT: del devmap : loop0p2
del devmap : loop0p1

2021-08-22 12:56:37 DEBUG STDERR: loop deleted : /dev/loop0

2021-08-22 12:56:37 INFO Running teardown: {'mkpart': 'primary', 'device': 'test.img', 'start': '1G', 'end': '100%', 'tag': '/'}
2021-08-22 12:56:37 INFO Calling <bound method StepRunnerInterface.teardown of <mkpart_plugin.MkpartStepRunner object at 0x7f64e4603cd0>>
2021-08-22 12:56:37 INFO Running teardown: {'mkpart': 'primary', 'device': 'test.img', 'start': '0%', 'end': '1G', 'tag': 'efi'}
2021-08-22 12:56:37 INFO Calling <bound method StepRunnerInterface.teardown of <mkpart_plugin.MkpartStepRunner object at 0x7f64e4603cd0>>
2021-08-22 12:56:37 INFO Running teardown: {'mklabel': 'gpt', 'device': 'test.img'}
2021-08-22 12:56:37 INFO Calling <bound method StepRunnerInterface.teardown of <mklabel_plugin.MklabelStepRunner object at 0x7f64e4603ca0>>
2021-08-22 12:56:37 INFO Running teardown: {'mkimg': 'test.img', 'size': '4G'}
2021-08-22 12:56:37 INFO Calling <bound method StepRunnerInterface.teardown of <mkimg_plugin.MkimgStepRunner object at 0x7f64e4603c70>>
2021-08-22 12:56:37 ERROR An error occurred, exiting
