test-mic can fail / writes to qemu-nbd device do not persist
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
cloud-utils |
Fix Released
|
Undecided
|
Unassigned | ||
cloud-utils (Ubuntu) |
Fix Released
|
Medium
|
Unassigned |
Bug Description
### Whats going on here?
## test-mic is a test of mount-image-
##
## It populates some disk images and then uses mic to write some
## files (info.txt and data.txt)
## then calls mic again to verify the files are there.
##
## the failure i'm seeing is that one of the files written during
## the first mic is not present in the second.
##
## mic does:
## mount via qemu-nbd, run command, umount, qemu-nbd disconnect
##
this recreates at least 1 in 3 times in my local tests here.
$ uname -r
4.13.0-17-generic
$ dpkg-query --show qemu-utils
qemu-utils 1:2.10+
$ bzr branch lp:cloud-utils cloud-utils
$ cd cloud-utils
## the output below has some debug info added
$ sudo PATH=$PWD/bin:$PATH ./test/test-mic 2>&1 | tee out.log
testing partition 1 image
testing partition 2 image
testing --system-mounts on pt1
testing unexpected mount get unmounted.
writing hunks to disk image /tmp/test-
partitioning MBR disk image /tmp/test-
partitioning GPT disk image /tmp/test-
MBR: testing partition 1 in /tmp/test-
pid for /dev/nbd0 is 30004
connected /tmp/test-
mounted /dev/nbd0p1 via qemu-nbd /dev/nbd0 at /tmp/mount-
invoking: MOUNTPOINT=
cmd returned 0. unmounting /tmp/mount-
disconnecting /dev/nbd0
pid for /dev/nbd0 is 30077
connected /tmp/test-
mounted /dev/nbd0p1 via qemu-nbd /dev/nbd0 at /tmp/mount-
invoking: MOUNTPOINT=
r=0; for f in "$@"; do
cat $f || { echo "$f: cat failed rc=$?"; r=99; }; done;
exit $r sh-extract info.txt data.txt
cmd returned 0. unmounting /tmp/mount-
disconnecting /dev/nbd0
MBR: testing partition 2 in /tmp/test-
pid for /dev/nbd0 is 30153
connected /tmp/test-
mounted /dev/nbd0p2 via qemu-nbd /dev/nbd0 at /tmp/mount-
invoking: MOUNTPOINT=
cmd returned 0. unmounting /tmp/mount-
disconnecting /dev/nbd0
pid for /dev/nbd0 is 30222
connected /tmp/test-
mounted /dev/nbd0p2 via qemu-nbd /dev/nbd0 at /tmp/mount-
invoking: MOUNTPOINT=
r=0; for f in "$@"; do
cat $f || { echo "$f: cat failed rc=$?"; r=99; }; done;
exit $r sh-extract info.txt data.txt
cat: data.txt: No such file or directory
cmd returned 99. unmounting /tmp/mount-
disconnecting /dev/nbd0
MBR:
== expected on 2 ==
partition 2
foo2
== found on 2 ==
partition 2
data.txt: cat failed rc=1
MBR: failed testing partition 2 on /tmp/test-
smoser@
testing partition 1 image
testing partition 2 image
testing --system-mounts on pt1
testing unexpected mount get unmounted.
writing hunks to disk image /tmp/test-
partitioning MBR disk image /tmp/test-
partitioning GPT disk image /tmp/test-
MBR: testing partition 1 in /tmp/test-
pid for /dev/nbd0 is 30674
connected /tmp/test-
mounted /dev/nbd0p1 via qemu-nbd /dev/nbd0 at /tmp/mount-
invoking: MOUNTPOINT=
cmd returned 0. unmounting /tmp/mount-
disconnecting /dev/nbd0
waiting on pidfile for /dev/nbd0 in /sys/block/nbd0/pid
.
pid for /dev/nbd0 is 30757
connected /tmp/test-
mounted /dev/nbd0p1 via qemu-nbd /dev/nbd0 at /tmp/mount-
invoking: MOUNTPOINT=
r=0; for f in "$@"; do
cat $f || { echo "$f: cat failed rc=$?"; r=99; }; done;
exit $r sh-extract info.txt data.txt
cat: data.txt: No such file or directory
cmd returned 99. unmounting /tmp/mount-
disconnecting /dev/nbd0
MBR:
== expected on 1 ==
partition 1
foo1
== found on 1 ==
partition 1
data.txt: cat failed rc=1
MBR: failed testing partition 1 on /tmp/test-
### new data in dmesg during run
[1300609.359437] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300609.506371] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300609.619183] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300609.752534] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300609.889312] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300610.022198] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300610.225399] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300610.374885] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300610.634821] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300610.830573] EXT4-fs (loop3): mounted filesystem with ordered data mode. Opts: (null)
[1300612.701430] nbd0: p1 p2
[1300612.713894] EXT4-fs (nbd0p1): mounted filesystem with ordered data mode. Opts: (null)
[1300612.798977] block nbd0: NBD_DISCONNECT
[1300612.799003] block nbd0: shutting down sockets
[1300612.800582] print_req_error: 22 callbacks suppressed
[1300612.800584] print_req_error: I/O error, dev nbd0, sector 18954
[1300612.800590] EXT4-fs warning (device nbd0p1): ext4_end_bio:322: I/O error 10 writing to inode 15 (offset 0 size 0 starting block 9478)
[1300612.800592] Buffer I/O error on device nbd0p1, logical block 8453
[1300612.800614] print_req_error: I/O error, dev nbd0, sector 100354
[1300612.800616] buffer_io_error: 17 callbacks suppressed
[1300612.800617] Buffer I/O error on dev nbd0p1, logical block 49153, lost sync page write
[1300612.800622] JBD2: Error -5 detected when updating journal superblock for nbd0p1-8.
[1300612.800623] Aborting journal on device nbd0p1-8.
[1300612.800630] print_req_error: I/O error, dev nbd0, sector 100354
[1300612.800632] Buffer I/O error on dev nbd0p1, logical block 49153, lost sync page write
[1300612.800636] JBD2: Error -5 detected when updating journal superblock for nbd0p1-8.
[1300612.800643] JBD2: Detected IO errors while flushing file data on nbd0p1-8
[1300612.800664] print_req_error: I/O error, dev nbd0, sector 0
[1300612.800693] print_req_error: I/O error, dev nbd0, sector 0
[1300612.800708] print_req_error: I/O error, dev nbd0, sector 0
[1300612.800723] print_req_error: I/O error, dev nbd0, sector 0
[1300612.800815] print_req_error: I/O error, dev nbd0, sector 2050
[1300612.800817] Buffer I/O error on dev nbd0p1, logical block 1, lost sync page write
[1300612.837164] nbd0: p1 p2
[1300612.953403] EXT4-fs (nbd0p1): INFO: recovery required on readonly filesystem
[1300612.953405] EXT4-fs (nbd0p1): write access will be enabled during recovery
[1300612.953745] EXT4-fs (nbd0p1): recovery complete
[1300612.954785] EXT4-fs (nbd0p1): mounted filesystem with ordered data mode. Opts: (null)
[1300613.011345] block nbd0: NBD_DISCONNECT
[1300613.011378] block nbd0: shutting down sockets
[1300613.015916] nbd0: detected capacity change from 0 to 316669952
[1300613.016004] print_req_error: I/O error, dev nbd0, sector 0
[1300613.016010] Buffer I/O error on dev nbd0, logical block 0, async page read
[1300613.016027] print_req_error: I/O error, dev nbd0, sector 0
[1300613.016030] Buffer I/O error on dev nbd0, logical block 0, async page read
[1300613.016039] Buffer I/O error on dev nbd0, logical block 0, async page read
[1300613.016044] ldm_validate_
[1300613.016050] Buffer I/O error on dev nbd0, logical block 0, async page read
[1300613.016058] Buffer I/O error on dev nbd0, logical block 0, async page read
[1300613.016066] Buffer I/O error on dev nbd0, logical block 0, async page read
[1300613.016074] Buffer I/O error on dev nbd0, logical block 0, async page read
[1300613.016078] Dev nbd0: unable to read RDB block 0
[1300613.016136] nbd0: unable to read partition table
ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: cloud-utils 0.30-0ubuntu2
ProcVersionSign
Uname: Linux 4.13.0-17-generic x86_64
NonfreeKernelMo
ApportVersion: 2.20.8-0ubuntu5
Architecture: amd64
CurrentDesktop: ubuntu:GNOME
Date: Wed Jan 3 11:47:00 2018
EcryptfsInUse: Yes
InstallationDate: Installed on 2015-07-23 (895 days ago)
InstallationMedia: Ubuntu 15.10 "Wily Werewolf" - Alpha amd64 (20150722.1)
PackageArchitec
ProcEnviron:
TERM=xterm-
PATH=(custom, no user)
XDG_RUNTIME_
LANG=en_US.UTF-8
SHELL=/bin/bash
SourcePackage: cloud-utils
UpgradeStatus: No upgrade log present (probably fresh install)
tags: | added: patch |
I've played a bit. Attached patch here has logging done with logger in an effort to serialize things.
Then, I have 'go.sh' (see below) that just loops over running test-mic until it fails.
Then you get bookend messages in /var/log/syslog. I've collected a fail here.