curtin

Recently introduced reuse-lvm-member-partition tests fail with rsync errors

Bug #1873909 reported by Dan Watkins
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
curtin
Fix Released
Undecided
Ryan Harper

Bug Description

The relevant part of the log from https://jenkins.ubuntu.com/server/job/curtin-vmtest-daily-x/579/:

12:06:54 2020-04-19 16:06:54,186 - BionicTestReuseLVMMemberPartition - INFO - BionicTestReuseLVMMemberPartition[install]: boot took 77.79 seconds. returned True
12:06:54 2020-04-19 16:06:54,673 - BionicTestReuseLVMMemberPartition - ERROR - Found error: Errors during curtin installer
12:06:54 2020-04-19 16:06:54,673 - BionicTestReuseLVMMemberPartition - ERROR - Context:
12:06:54 [ 61.676908] cloud-init[992]: finish: cmd-install/stage-early: FAIL: preparing for installation
12:06:54 [ 61.679101] cloud-init[992]: curtin: Installation failed with exception: Unexpected error while running command.
12:06:54 [ 61.685246] cloud-init[992]: Command: ['sh', '-exuc', 'SDA=/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a\nSDB=/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b\nVG="vg8"\nLV="lv1_root"\nparted ${SDA} --script -- \\\n mklabel gpt \\\n mkpart primary 1GiB 2GiB \\\n set 1 esp on \\\n mkpart primary 2GiB 9GiB\nparted ${SDB} --script -- \\\n mklabel gpt \\\n mkpart primary 2GiB 9GiB\nudevadm settle\nvgcreate --verbose --force --zero=y --yes ${VG} ${SDA}-part2 ${SDB}-part1\npvscan --verbose --cache\nvgscan --verbose --mknodes\n# create a striped lv\nlvcreate ${VG} --extents 100%FREE --stripes 2 --stripesize 256 \\\n --name ${LV}\nudevadm settle\n# populate the lv with data to ensure we allocate extents on both pv devs\nmkfs.ext4 /dev/${VG}/${LV}\nmount /dev/${VG}/${LV} /mnt\nrsync -aqpP /var /mnt\numount /mnt\n# simulate the first boot environment by turning off the vg, and wiping\n# one physical volume\nfor vg in `pvdisplay -C --separator = -o vg_name --noheadings`; do\n vgchange --verbose -an $vg ||:\ndone\nrm -rf /etc/lvm/archive /etc/lvm/backup /run/lvm\nwipefs -a ${SDB}-part1\nmkfs.ext4 ${SDB}-part1\nudevadm settle\nudevadm trigger --subsystem-match=block\nudevadm settle\nexit 0\n']
12:06:54 [ 61.705075] cloud-init[992]: Exit code: 23
12:06:54 [ 61.705858] cloud-init[992]: Reason: -
12:06:54 [ 61.706718] cloud-init[992]: Stdout: + SDA=/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a
12:06:54 [ 61.711890] cloud-init[992]: + SDB=/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b
12:06:54 [ 61.713101] cloud-init[992]: + VG=vg8
12:06:54 [ 61.713897] cloud-init[992]: + LV=lv1_root
12:06:54 [ 61.718346] cloud-init[992]: + parted /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a --script -- mklabel gpt mkpart primary 1GiB 2GiB set 1 esp on mkpart primary 2GiB 9GiB
12:06:54 [ 61.722452] cloud-init[992]: + parted /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b --script -- mklabel gpt mkpart primary 2GiB 9GiB
12:06:54 [ 61.726885] cloud-init[992]: + udevadm settle
12:06:54 [ 61.727837] cloud-init[992]: + vgcreate --verbose --force --zero=y --yes vg8 /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a-part2 /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b-part1
12:06:54 [ 61.732377] cloud-init[992]: Wiping internal VG cache
12:06:54 [ 61.733353] cloud-init[992]: Wiping cache of LVM-capable devices
12:06:54 [ 61.737307] cloud-init[992]: Wiping signatures on new PV /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a-part2.
12:06:54 [ 61.742065] cloud-init[992]: Wiping signatures on new PV /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b-part1.
12:06:54 [ 61.746262] cloud-init[992]: Set up physical volume for "/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a-part2" with 14680064 available sectors.
12:06:54 [ 61.751913] cloud-init[992]: Zeroing start of device /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a-part2.
12:06:54 [ 61.753284] cloud-init[992]: Writing physical volume data to disk "/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a-part2".
12:06:54 [ 61.756565] cloud-init[992]: Physical volume "/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-a-part2" successfully created.
12:06:54 [ 61.759931] cloud-init[992]: Set up physical volume for "/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b-part1" with 14680064 available sectors.
12:06:54 [ 61.763614] cloud-init[992]: Zeroing start of device /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b-part1.
12:06:54 [ 61.767612] cloud-init[992]: Writing physical volume data to disk "/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b-part1".
12:06:54 [ 61.769146] cloud-init[992]: Physical volume "/dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_disk-b-part1" successfully created.
12:06:54 [ 61.771615] cloud-init[992]: Adding physical volume '/dev/sda2' to volume group 'vg8'
12:06:54 [ 61.776221] cloud-init[992]: Adding physical volume '/dev/sdb1' to volume group 'vg8'
12:06:54 [ 61.777444] cloud-init[992]: Creating directory "/etc/lvm/archive"
12:06:54 [ 61.778555] cloud-init[992]: Archiving volume group "vg8" metadata (seqno 0).
12:06:54 [ 61.783741] cloud-init[992]: Creating directory "/etc/lvm/backup"
12:06:54 [ 61.784806] cloud-init[992]: Creating volume group backup "/etc/lvm/backup/vg8" (seqno 1).
12:06:54 [ 61.786032] cloud-init[992]: Volume group "vg8" successfully created
12:06:54 [ 61.787084] cloud-init[992]: + pvscan --verbose --cache
12:06:54 [ 61.791855] cloud-init[992]: Scanning all devices.
12:06:54 [ 61.792803] cloud-init[992]: Scanning all devices to update lvmetad.
12:06:54 [ 61.793873] cloud-init[992]: No PV label found on /dev/loop0.
12:06:54 [ 61.795626] cloud-init[992]: No PV label found on /dev/sda1.
12:06:54 [ 61.799624] cloud-init[992]: No PV label found on /dev/sdc.
12:06:54 [ 61.800659] cloud-init[992]: + vgscan --verbose --mknodes
12:06:54 [ 61.801613] cloud-init[992]: Wiping cache of LVM-capable devices
12:06:54 [ 61.803620] cloud-init[992]: Wiping internal VG cache
12:06:54 [ 61.807609] cloud-init[992]: Reading volume groups from cache.
12:06:54 [ 61.808658] cloud-init[992]: Found volume group "vg8" using metadata type lvm2
12:06:54 [ 61.809778] cloud-init[992]: + lvcreate vg8 --extents 100%FREE --stripes 2 --stripesize 256 --name lv1_root
12:06:54 [ 61.815607] cloud-init[992]: Logical volume "lv1_root" created.
12:06:54 [ 61.816659] cloud-init[992]: + udevadm settle
12:06:54 [ 61.817520] cloud-init[992]: + mkfs.ext4 /dev/vg8/lv1_root
12:06:54 [ 61.818479] cloud-init[992]: mke2fs 1.44.1 (24-Mar-2018)
12:06:54 [ 61.819424] cloud-init[992]: Discarding device blocks: 4096/3667968 done
12:06:54 [ 61.824899] cloud-init[992]: Creating filesystem with 3667968 4k blocks and 917504 inodes
12:06:54 [ 61.826141] cloud-init[992]: Filesystem UUID: 6e3ab4ba-4bc5-4a20-bfd8-f85a2f1551b7
12:06:54 [ 61.827271] cloud-init[992]: Superblock backups stored on blocks:
12:06:54 [ 61.831614] cloud-init[992]: 32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208
12:06:54 [ 61.832968] cloud-init[992]:
12:06:54 [ 61.833714] cloud-init[992]: Allocating group tables: 0/112 done
12:06:54 [ 61.835619] cloud-init[992]: Writing inode tables: 0/112 done
12:06:54 [ 61.839611] cloud-init[992]: Creating journal (16384 blocks): done
12:06:54 [ 61.840671] cloud-init[992]: Writing superblocks and filesystem accounting information: 0/112 done
12:06:54 [ 61.843622] cloud-init[992]:
12:06:54 [ 61.844403] cloud-init[992]: + mount /dev/vg8/lv1_root /mnt
12:06:54 [ 61.846401] cloud-init[992]: + rsync -aqpP /var /mnt
12:06:54 [ 61.851607] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.853172] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.854784] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/accounts-daemon.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.860089] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/apparmor.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.863611] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/apport.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.867312] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/atd.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.869111] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/blk-availability.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.875625] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/cloud-config.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.877591] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/cloud-final.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.883806] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/cloud-init-local.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.885657] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/cloud-init.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.887420] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/console-setup.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.893303] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/cron.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.895027] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/dbus.service/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.899889] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/dev-hugepages.mount/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.903622] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/dev-mqueue.mount/blkio.reset_stats": Permission denied (13)
12:06:54 [ 61.905413] cloud-init[992]: rsync: send_files failed to open "/var/lib/lxcfs/cgroup/blkio/system.slice/ebtables.service/blkio.reset_stats": Permission denied (13)
<snip>

(There are lots more similar errors, all in /var/lib/lxcfs/cgroup.)

Related branches

~raharper/curtin:ubuntu-devel-new-upstream-snapshot-20200507
Server Team CI bot: Needs Fixing (continuous-integration)
Chad Smith: Approve
Diff: 10726 lines (+6948/-918)
83 files modified
Makefile (+15/-6)
curtin/__init__.py (+2/-0)
curtin/block/__init__.py (+190/-12)
curtin/block/bcache.py (+242/-1)
curtin/block/clear_holders.py (+34/-51)
curtin/block/lvm.py (+43/-6)
curtin/block/mdadm.py (+10/-25)
curtin/block/mkfs.py (+8/-2)
curtin/block/multipath.py (+90/-11)
curtin/block/schemas.py (+13/-2)
curtin/commands/apt_config.py (+1/-5)
curtin/commands/block_discover.py (+11/-2)
curtin/commands/block_meta.py (+597/-474)
curtin/commands/clear_holders.py (+44/-9)
curtin/commands/curthooks.py (+225/-38)
curtin/distro.py (+18/-1)
curtin/storage_config.py (+64/-36)
curtin/udev.py (+25/-2)
curtin/util.py (+13/-2)
debian/changelog (+58/-0)
dev/null (+0/-6)
doc/topics/storage.rst (+108/-19)
examples/tests/bcache-ceph-nvme-simple.yaml (+2/-2)
examples/tests/bcache-ceph-nvme.yaml (+2/-2)
examples/tests/filesystem_battery.yaml (+1/-0)
examples/tests/mirrorboot-uefi.yaml (+17/-1)
examples/tests/multipath-lvm-part-wipe.yaml (+125/-0)
examples/tests/multipath-lvm.yaml (+121/-0)
examples/tests/multipath.yaml (+6/-0)
examples/tests/preserve-bcache.yaml (+82/-0)
examples/tests/preserve-lvm.yaml (+77/-0)
examples/tests/preserve-partition-wipe-vg-simple.yaml (+62/-0)
examples/tests/preserve-partition-wipe-vg.yaml (+116/-0)
examples/tests/preserve-raid.yaml (+4/-2)
examples/tests/reuse-lvm-member-partition.yaml (+94/-0)
examples/tests/reuse-msdos-partitions.yaml (+77/-0)
examples/tests/reuse-raid-member-wipe-partition.yaml (+2/-0)
examples/tests/reuse-raid-member-wipe.yaml (+2/-1)
examples/tests/uefi_reuse_esp.yaml (+4/-2)
examples/tests/vmtest_defaults.yaml (+19/-1)
helpers/common (+11/-5)
tests/data/probert_storage_bogus_wwn.json (+1258/-0)
tests/data/probert_storage_nvme_multipath.json (+310/-0)
tests/data/udevadm_info_sandisk_cruzer.txt (+54/-0)
tests/unittests/helpers.py (+52/-3)
tests/unittests/test_apt_custom_sources_list.py (+2/-0)
tests/unittests/test_apt_source.py (+2/-0)
tests/unittests/test_block.py (+104/-5)
tests/unittests/test_block_lvm.py (+31/-1)
tests/unittests/test_block_mdadm.py (+8/-6)
tests/unittests/test_block_mkfs.py (+9/-0)
tests/unittests/test_block_multipath.py (+45/-0)
tests/unittests/test_block_zfs.py (+24/-20)
tests/unittests/test_clear_holders.py (+51/-37)
tests/unittests/test_commands_block_meta.py (+885/-7)
tests/unittests/test_commands_clear_holders.py (+24/-0)
tests/unittests/test_commands_collect_logs.py (+2/-0)
tests/unittests/test_curthooks.py (+483/-8)
tests/unittests/test_distro.py (+51/-2)
tests/unittests/test_gpg.py (+50/-44)
tests/unittests/test_make_dname.py (+3/-3)
tests/unittests/test_storage_config.py (+189/-3)
tests/unittests/test_udev.py (+43/-6)
tests/unittests/test_util.py (+25/-2)
tests/vmtests/__init__.py (+53/-17)
tests/vmtests/releases.py (+20/-3)
tests/vmtests/test_basic.py (+33/-19)
tests/vmtests/test_fs_battery.py (+7/-0)
tests/vmtests/test_mdadm_bcache.py (+34/-0)
tests/vmtests/test_multipath.py (+80/-3)
tests/vmtests/test_multipath_lvm.py (+76/-0)
tests/vmtests/test_preserve_bcache.py (+67/-0)
tests/vmtests/test_preserve_lvm.py (+80/-0)
tests/vmtests/test_preserve_partition_wipe_vg.py (+59/-0)
tests/vmtests/test_reuse_lvm_member.py (+34/-0)
tests/vmtests/test_reuse_msdos_partitions.py (+31/-0)
tests/vmtests/test_reuse_raid_member.py (+1/-1)
tests/vmtests/test_ubuntu_core.py (+9/-0)
tools/block-discover-to-config (+1/-1)
tools/schema-validate-storage (+1/-0)
tools/vmtest-filter (+2/-1)
tools/vmtest-sync-images (+1/-0)
tox.ini (+19/-0)
~raharper/curtin:fix/vmtest-early-rsync-error
Server Team CI bot: Approve (continuous-integration)
Chad Smith: Approve
Diff: 13 lines (+1/-1)
1 file modified
examples/tests/reuse-lvm-member-partition.yaml (+1/-1)
Revision history for this message
Dan Watkins (oddbloke) wrote :

Assigned to Ryan as he mentioned in IRC that he had a fix.

Changed in curtin:
assignee: nobody → Dan Watkins (daniel-thewatkins)
assignee: Dan Watkins (daniel-thewatkins) → Ryan Harper (raharper)
status: New → In Progress
Revision history for this message
Server Team CI bot (server-team-bot) wrote :

This bug is fixed with commit 9d85462a to curtin on branch master.
To view that commit see the following URL:
https://git.launchpad.net/curtin/commit/?id=9d85462a

Changed in curtin:
status: In Progress → Fix Committed
Revision history for this message
Ryan Harper (raharper) wrote : Fixed in curtin version 20.1.

This bug is believed to be fixed in curtin in version 20.1. If this is still a problem for you, please make a comment and set the state back to New

Thank you.

Changed in curtin:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.