"Roberto C. Sanchez" <robe...@debian.org> writes: > > Attempting to build qemu images fails as follows: > > roberto@debian:~$ sudo autopkgtest-build-qemu buster ./autopkgtest-buster.img > Load spec file /tmp/user/0/tmph19aaviw/vmdb2.yaml > Exec: ['dpkg', '--print-architecture'] > Exec: ['qemu-img', 'create', '-f', 'raw', './autopkgtest-buster.img.raw', > '25G'] > Exec: ['parted', '-s', './autopkgtest-buster.img.raw', 'mklabel', 'msdos'] > Exec: ['parted', '-m', '/home/roberto/autopkgtest-buster.img.raw', 'print'] > Exec: ['parted', '-s', '/home/roberto/autopkgtest-buster.img.raw', '--', > 'mkpart', 'primary', 'ext2', '0%', '100%'] > Exec: ['parted', '-m', '/home/roberto/autopkgtest-buster.img.raw', 'print'] > Exec: ['kpartx', '-asv', './autopkgtest-buster.img.raw'] > remembering /dev/mapper/loop0p1 as root > Exec: ['/sbin/mkfs', '-t', 'ext4', '/dev/mapper/loop0p1'] > Exec: ['mount', '/dev/mapper/loop0p1', '/tmp/user/0/tmpllucvne5'] > Exec: ['debootstrap', '--variant', '-', 'buster', '/tmp/user/0/tmpllucvne5', > 'http://deb.debian.org/debian'] > Exec: ['chroot', '/tmp/user/0/tmpllucvne5', 'apt-get', 'update'] > Exec: ['chroot', '/tmp/user/0/tmpllucvne5', 'apt-get', 'update'] > Exec: ['chroot', '/tmp/user/0/tmpllucvne5', 'apt-get', '-y', > '--no-show-progress', 'install', 'eatmydata'] > Exec: ['chroot', '/tmp/user/0/tmpllucvne5', 'eatmydata', 'apt-get', 'update'] > Exec: ['chroot', '/tmp/user/0/tmpllucvne5', 'eatmydata', 'apt-get', '-y', > '--no-show-progress', 'install', 'linux-image-amd64', 'ifupdown'] > ERROR:root:Program failed: 100 > 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/apt_plugin.py", line 47, > in run > self.install_packages(mount_point, ["eatmydata"], packages) > File "/usr/lib/python3/dist-packages/vmdb/plugins/apt_plugin.py", line 61, > in install_packages > vmdb.runcmd_chroot( > File "/usr/lib/python3/dist-packages/vmdb/runcmd.py", line 64, in > runcmd_chroot > return runcmd(full_argv, *argvs, **kwargs) > 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: 100
This is still happening with 5.30.
Load spec file /tmp/tmp9w769cua/vmdb2.yaml Exec: ['dpkg', '--print-architecture'] Exec: ['qemu-img', 'create', '-f', 'raw', '/home/bremner/var/images/autopkgtest-sid-i386.raw', '25G'] Exec: ['parted', '-s', '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'mklabel', 'msdos'] Exec: ['parted', '-m', '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'print'] Exec: ['parted', '-s', '/home/bremner/var/images/autopkgtest-sid-i386.raw', '--', 'mkpart', 'primary', 'ext2', '0%', '100%'] Exec: ['parted', '-m', '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'print'] Exec: ['kpartx', '-asv', '/home/bremner/var/images/autopkgtest-sid-i386.raw'] remembering /dev/mapper/loop0p1 as root Exec: ['/sbin/mkfs', '-t', 'ext4', '-O', '^large_dir', '-O', '^metadata_csum_seed', '/dev/mapper/loop0p1'] Exec: ['blkid', '-c/dev/null', '-ovalue', '-sUUID', '/dev/mapper/loop0p1'] Exec: ['mount', '/dev/mapper/loop0p1', '/tmp/tmppt5v6frz'] Exec: ['qemu-debootstrap', '--arch', 'i386', '--variant', '-', '--components', 'main', 'sid', '/tmp/tmppt5v6frz', 'https://deb.debian.org/debian'] ERROR: [Errno 2] No such file or directory: 'qemu-debootstrap' ERROR: FileNotFoundError(2, 'No such file or directory') Something went wrong, cleaning up! Exec: ['zerofree', '-v', '/dev/mapper/loop0p1'] ERROR: [Errno 2] No such file or directory: 'zerofree' ERROR: FileNotFoundError(2, 'No such file or directory') Exec: ['kpartx', '-dsv', '/home/bremner/var/images/autopkgtest-sid-i386.raw'] Exec: ['losetup', '--json', '-l', '/dev/loop0'] 2023-09-17 11:32:21 INFO Starting vmdb2 version 0.26 2023-09-17 11:32:21 INFO Load spec file /tmp/tmp9w769cua/vmdb2.yaml 2023-09-17 11:32:21 INFO Exec: ['dpkg', '--print-architecture'] 2023-09-17 11:32:21 DEBUG STDOUT: amd64 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Running step: {'mkimg': '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'size': '25G'} 2023-09-17 11:32:21 INFO Calling <bound method MkimgStepRunner.run of <mkimg_plugin.MkimgStepRunner object at 0x7fc51a205890>> 2023-09-17 11:32:21 INFO Exec: ['qemu-img', 'create', '-f', 'raw', '/home/bremner/var/images/autopkgtest-sid-i386.raw', '25G'] 2023-09-17 11:32:21 DEBUG STDOUT: Formatting '/home/bremner/var/images/autopkgtest-sid-i386.raw', fmt=raw size=26843545600 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkimg_plugin.MkimgStepRunner object at 0x7fc51a205890>> 2023-09-17 11:32:21 INFO Running step: {'mklabel': 'msdos', 'device': '/home/bremner/var/images/autopkgtest-sid-i386.raw'} 2023-09-17 11:32:21 INFO Calling <bound method MklabelStepRunner.run of <mklabel_plugin.MklabelStepRunner object at 0x7fc51a205850>> 2023-09-17 11:32:21 INFO Exec: ['parted', '-s', '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'mklabel', 'msdos'] 2023-09-17 11:32:21 DEBUG STDOUT: 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mklabel_plugin.MklabelStepRunner object at 0x7fc51a205850>> 2023-09-17 11:32:21 INFO Running step: {'mkpart': 'primary', 'device': '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'start': '0%', 'end': '100%', 'tag': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method MkpartStepRunner.run of <mkpart_plugin.MkpartStepRunner object at 0x7fc51ad8c210>> 2023-09-17 11:32:21 INFO Exec: ['parted', '-m', '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'print'] 2023-09-17 11:32:21 DEBUG STDOUT: BYT; /home/bremner/var/images/autopkgtest-sid-i386.raw:26.8GB:file:512:512:msdos::; 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Exec: ['parted', '-s', '/home/bremner/var/images/autopkgtest-sid-i386.raw', '--', 'mkpart', 'primary', 'ext2', '0%', '100%'] 2023-09-17 11:32:21 DEBUG STDOUT: 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Exec: ['parted', '-m', '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'print'] 2023-09-17 11:32:21 DEBUG STDOUT: BYT; /home/bremner/var/images/autopkgtest-sid-i386.raw:26.8GB:file:512:512:msdos::; 1:1049kB:26.8GB:26.8GB:::; 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkpart_plugin.MkpartStepRunner object at 0x7fc51ad8c210>> 2023-09-17 11:32:21 INFO Running step: {'kpartx': '/home/bremner/var/images/autopkgtest-sid-i386.raw'} 2023-09-17 11:32:21 INFO Calling <bound method KpartxStepRunner.run of <kpartx_plugin.KpartxStepRunner object at 0x7fc51a205790>> 2023-09-17 11:32:21 INFO Exec: ['kpartx', '-asv', '/home/bremner/var/images/autopkgtest-sid-i386.raw'] 2023-09-17 11:32:21 DEBUG STDOUT: add map loop0p1 (254:4): 0 52426752 linear 7:0 2048 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO remembering /dev/mapper/loop0p1 as root 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <kpartx_plugin.KpartxStepRunner object at 0x7fc51a205790>> 2023-09-17 11:32:21 INFO Running step: {'mkfs': 'ext4', 'partition': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method MkfsStepRunner.run of <mkfs_plugin.MkfsStepRunner object at 0x7fc51a205610>> 2023-09-17 11:32:21 INFO Exec: ['/sbin/mkfs', '-t', 'ext4', '-O', '^large_dir', '-O', '^metadata_csum_seed', '/dev/mapper/loop0p1'] 2023-09-17 11:32:21 DEBUG STDOUT: Discarding device blocks: 0/6553344 done Creating filesystem with 6553344 4k blocks and 1638400 inodes Filesystem UUID: 8d96a3f1-bccf-49d6-bb98-02a7539fc28a Superblock backups stored on blocks: 32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208, 4096000 Allocating group tables: 0/200 done Writing inode tables: 0/200 done Creating journal (32768 blocks): done Writing superblocks and filesystem accounting information: 0/200 done 2023-09-17 11:32:21 DEBUG STDERR: mke2fs 1.47.0 (5-Feb-2023) 2023-09-17 11:32:21 INFO Exec: ['blkid', '-c/dev/null', '-ovalue', '-sUUID', '/dev/mapper/loop0p1'] 2023-09-17 11:32:21 DEBUG STDOUT: 8d96a3f1-bccf-49d6-bb98-02a7539fc28a 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mkfs_plugin.MkfsStepRunner object at 0x7fc51a205610>> 2023-09-17 11:32:21 INFO Running step: {'mount': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method MountStepRunner.run of <mount_plugin.MountStepRunner object at 0x7fc51a2052d0>> 2023-09-17 11:32:21 INFO Exec: ['mount', '/dev/mapper/loop0p1', '/tmp/tmppt5v6frz'] 2023-09-17 11:32:21 DEBUG STDOUT: 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.run_even_if_skipped of <mount_plugin.MountStepRunner object at 0x7fc51a2052d0>> 2023-09-17 11:32:21 INFO Running step: {'qemu-debootstrap': 'sid', 'arch': 'i386', 'mirror': 'https://deb.debian.org/debian', 'target': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method QemuDebootstrapStepRunner.run of <qemudebootstrap_plugin.QemuDebootstrapStepRunner object at 0x7fc51ac12150>> 2023-09-17 11:32:21 INFO Exec: ['qemu-debootstrap', '--arch', 'i386', '--variant', '-', '--components', 'main', 'sid', '/tmp/tmppt5v6frz', 'https://deb.debian.org/debian'] 2023-09-17 11:32:21 ERROR [Errno 2] No such file or directory: 'qemu-debootstrap' Traceback (most recent call last): File "/usr/lib/python3/dist-packages/vmdb/app.py", line 243, 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 53, in runcmd p = subprocess.Popen(argv, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/subprocess.py", line 1026, in __init__ self._execute_child(args, executable, preexec_fn, close_fds, File "/usr/lib/python3.11/subprocess.py", line 1950, in _execute_child raise child_exception_type(errno_num, err_msg, err_filename) FileNotFoundError: [Errno 2] No such file or directory: 'qemu-debootstrap' 2023-09-17 11:32:21 ERROR FileNotFoundError(2, 'No such file or directory') Traceback (most recent call last): File "/usr/lib/python3/dist-packages/vmdb/app.py", line 243, 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 53, in runcmd p = subprocess.Popen(argv, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/subprocess.py", line 1026, in __init__ self._execute_child(args, executable, preexec_fn, close_fds, File "/usr/lib/python3.11/subprocess.py", line 1950, in _execute_child raise child_exception_type(errno_num, err_msg, err_filename) FileNotFoundError: [Errno 2] No such file or directory: 'qemu-debootstrap' 2023-09-17 11:32:21 INFO Something went wrong, cleaning up! 2023-09-17 11:32:21 INFO Running teardown: {'qemu-debootstrap': 'sid', 'arch': 'i386', 'mirror': 'https://deb.debian.org/debian', 'target': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.teardown of <qemudebootstrap_plugin.QemuDebootstrapStepRunner object at 0x7fc51ac12150>> 2023-09-17 11:32:21 INFO Running teardown: {'mount': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method MountStepRunner.teardown of <mount_plugin.MountStepRunner object at 0x7fc51a2052d0>> 2023-09-17 11:32:21 DEBUG Unmounting /tmp/tmppt5v6frz and everything on top of it 2023-09-17 11:32:21 DEBUG Finished unmounting /tmp/tmppt5v6frz 2023-09-17 11:32:21 INFO Exec: ['zerofree', '-v', '/dev/mapper/loop0p1'] 2023-09-17 11:32:21 ERROR [Errno 2] No such file or directory: 'zerofree' Traceback (most recent call last): File "/usr/lib/python3/dist-packages/vmdb/app.py", line 243, in run_steps_helper method(values, settings, state) File "/usr/lib/python3/dist-packages/vmdb/plugins/mount_plugin.py", line 46, in teardown vmdb.runcmd(["zerofree", "-v", dev]) File "/usr/lib/python3/dist-packages/vmdb/runcmd.py", line 53, in runcmd p = subprocess.Popen(argv, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/subprocess.py", line 1026, in __init__ self._execute_child(args, executable, preexec_fn, close_fds, File "/usr/lib/python3.11/subprocess.py", line 1950, in _execute_child raise child_exception_type(errno_num, err_msg, err_filename) FileNotFoundError: [Errno 2] No such file or directory: 'zerofree' 2023-09-17 11:32:21 ERROR FileNotFoundError(2, 'No such file or directory') Traceback (most recent call last): File "/usr/lib/python3/dist-packages/vmdb/app.py", line 243, in run_steps_helper method(values, settings, state) File "/usr/lib/python3/dist-packages/vmdb/plugins/mount_plugin.py", line 46, in teardown vmdb.runcmd(["zerofree", "-v", dev]) File "/usr/lib/python3/dist-packages/vmdb/runcmd.py", line 53, in runcmd p = subprocess.Popen(argv, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/subprocess.py", line 1026, in __init__ self._execute_child(args, executable, preexec_fn, close_fds, File "/usr/lib/python3.11/subprocess.py", line 1950, in _execute_child raise child_exception_type(errno_num, err_msg, err_filename) FileNotFoundError: [Errno 2] No such file or directory: 'zerofree' 2023-09-17 11:32:21 INFO Running teardown: {'mkfs': 'ext4', 'partition': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.teardown of <mkfs_plugin.MkfsStepRunner object at 0x7fc51a205610>> 2023-09-17 11:32:21 INFO Running teardown: {'kpartx': '/home/bremner/var/images/autopkgtest-sid-i386.raw'} 2023-09-17 11:32:21 INFO Calling <bound method KpartxStepRunner.teardown of <kpartx_plugin.KpartxStepRunner object at 0x7fc51a205790>> 2023-09-17 11:32:21 INFO Exec: ['kpartx', '-dsv', '/home/bremner/var/images/autopkgtest-sid-i386.raw'] 2023-09-17 11:32:21 DEBUG STDOUT: del devmap : loop0p1 2023-09-17 11:32:21 DEBUG STDERR: loop deleted : /dev/loop0 2023-09-17 11:32:21 INFO Exec: ['losetup', '--json', '-l', '/dev/loop0'] 2023-09-17 11:32:21 DEBUG STDOUT: { "loopdevices": [ { "name": "/dev/loop0", "sizelimit": null, "offset": null, "autoclear": false, "ro": false, "back-file": null, "dio": false, "log-sec": 512 } ] } 2023-09-17 11:32:21 DEBUG STDERR: 2023-09-17 11:32:21 INFO Running teardown: {'mkpart': 'primary', 'device': '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'start': '0%', 'end': '100%', 'tag': 'root'} 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.teardown of <mkpart_plugin.MkpartStepRunner object at 0x7fc51ad8c210>> 2023-09-17 11:32:21 INFO Running teardown: {'mklabel': 'msdos', 'device': '/home/bremner/var/images/autopkgtest-sid-i386.raw'} 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.teardown of <mklabel_plugin.MklabelStepRunner object at 0x7fc51a205850>> 2023-09-17 11:32:21 INFO Running teardown: {'mkimg': '/home/bremner/var/images/autopkgtest-sid-i386.raw', 'size': '25G'} 2023-09-17 11:32:21 INFO Calling <bound method StepRunnerInterface.teardown of <mkimg_plugin.MkimgStepRunner object at 0x7fc51a205890>> 2023-09-17 11:32:21 ERROR An error occurred, exiting Command '['/usr/bin/vmdb2', '--verbose', '--image=/home/bremner/var/images/autopkgtest-sid-i386.raw', '--log=/home/bremner/var/images/autopkgtest-sid-i386.log', '/tmp/tmp9w769cua/vmdb2.yaml']' returned non-zero exit status 1.
