Skip to content

Instantly share code, notes, and snippets.

@fridtjof
Last active September 14, 2020 15:45
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save fridtjof/dbf985c1a6e7ec2a0ee9d5ec3412aa76 to your computer and use it in GitHub Desktop.
Save fridtjof/dbf985c1a6e7ec2a0ee9d5ec3412aa76 to your computer and use it in GitHub Desktop.

Basic information:

  • DL385 G5 running Ubuntu 18.04.5 with OpenStack-Ansible Stein deployed (which changes the repos to bionic-updates/stein)
  • The /dev/mapper device is on an LVM2 sitting on a RAID5 of SSDs. / is mounted on a RAID1 of HDDs.
  • The command line is what Openstack's cinder-volume would call to create a volume from an image (except -p, which I added for demonstration purposes)

I got qemu-img from xenial-updates/queens, which was the last version I know worked normally. I also tested with 1:2.11+dfsg-1ubuntu7.31~cloud0, which was also available on cloud-archive.

root@storage:~# ./qemu-img --version
qemu-img version 2.11.1(Debian 1:2.11+dfsg-1ubuntu7.28~cloud0)
Copyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers

root@storage:~# time ./qemu-img convert -p -O raw -t none -f qcow2 tmpejN81Hstorage@lvm /dev/mapper/cinder--volumes-volume--9d18daa7--691c--44bc--b4c8--a60cc70a435d
    (100.00/100%)

real    0m35.114s
user    0m11.380s
sys     0m3.140s

This is the version shipped through bionic-updates/stein, which gets stuck completely

root@storage:~# qemu-img --version
qemu-img version 3.1.0 (Debian 1:3.1+dfsg-2ubuntu3.7~cloud0)
Copyright (c) 2003-2018 Fabrice Bellard and the QEMU Project developers
root@storage:~# time qemu-img convert -p -O raw -t none -f qcow2 tmpejN81Hstorage@lvm /dev/mapper/cinder--volumes-volume--9d18daa7--691c--44bc--b4c8--a60cc70a435d
^C  (0.00/100%)

real    0m46.707s
user    0m0.005s
sys     0m0.816s

This version is from bionic-updates/train, also working normally again:

root@storage:~# ./qemu-img --version
qemu-img version 4.0.0 (Debian 1:4.0+dfsg-0ubuntu9.8~cloud0)
Copyright (c) 2003-2019 Fabrice Bellard and the QEMU Project developers
root@storage:~# time ./qemu-img convert -p -O raw -t none -f qcow2 tmpejN81Hstorage@lvm /dev/mapper/cinder--volumes-volume--9d18daa7--691c--44bc--b4c8--a60cc70a435d
    (100.00/100%)

real    0m34.180s
user    0m13.380s
sys     0m3.579s

EDIT:

strace output for the broken version (1:3.1+dfsg-2ubuntu3.7~cloud0): (lines starting with # are my annotations)

[...]
fstatfs(10, {f_type=TMPFS_MAGIC, f_bsize=4096, f_blocks=4101329, f_bfree=4101329, f_bavail=4101329, f_files=4101329, f_ffree=4100748, f_fsid={val=[0, 0]}, f_namelen=255, f_frsize=4096, f_flags=ST_VALID|ST_NOSUID|ST_RELATIME}) = 0
fstat(10, {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 13), ...}) = 0
stat("/dev/mapper/cinder--volumes-volume--9d18daa7--691c--44bc--b4c8--a60cc70a435d", {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 13), ...}) = 0
fstat(10, {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 13), ...}) = 0
ioctl(10, BLKROGET, [0])                = 0
lseek(10, 0, SEEK_END)                  = 53687091200
fstat(10, {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 13), ...}) = 0
ioctl(10, BLKSECTGET, [1024])           = 0
openat(AT_FDCWD, "/sys/dev/block/253:13/queue/max_segments", O_RDONLY) = 11
read(11, "543\n", 31)                   = 4
close(11)                               = 0
ioctl(10, BLKSSZGET, [512])             = 0
pread64(10, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096, 0) = 4096
fstat(10, {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 13), ...}) = 0
ioctl(10, BLKSECTGET, [1024])           = 0
openat(AT_FDCWD, "/sys/dev/block/253:13/queue/max_segments", O_RDONLY) = 11
read(11, "543\n", 31)                   = 4
close(11)                               = 0
ioctl(10, BLKSSZGET, [512])             = 0
pread64(10, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096, 0) = 4096
fcntl(10, F_OFD_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=100, l_len=1}) = 0
fcntl(10, F_OFD_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=101, l_len=1}) = 0
fcntl(10, F_OFD_GETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=200, l_len=1, l_pid=0}) = 0
fcntl(10, F_OFD_GETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=201, l_len=1, l_pid=0}) = 0
########### this block will repeat over and over
rt_sigprocmask(SIG_BLOCK, NULL, [BUS USR1 ALRM IO], 8) = 0
mmap(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0bc89ef000
mprotect(0x7f0bc89ef000, 4096, PROT_NONE) = 0
rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], [BUS USR1 ALRM IO], 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [BUS USR1 ALRM IO], 8) = 0
mmap(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0bc88ee000
mprotect(0x7f0bc88ee000, 4096, PROT_NONE) = 0
rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], [BUS USR1 ALRM IO], 8) = 0
futex(0x565202a0fd78, FUTEX_WAKE_PRIVATE, 1) = 1
# !!!!! hangs here for some time:
ppoll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, NULL, NULL, 8) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 512)        = 8
#
rt_sigprocmask(SIG_BLOCK, NULL, [BUS USR1 ALRM IO], 8) = 0
mmap(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0bc87ed000
mprotect(0x7f0bc87ed000, 4096, PROT_NONE) = 0
rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], [BUS USR1 ALRM IO], 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [BUS USR1 ALRM IO], 8) = 0
mmap(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0bc86ec000
mprotect(0x7f0bc86ec000, 4096, PROT_NONE) = 0
rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], [BUS USR1 ALRM IO], 8) = 0
futex(0x565202a0fd78, FUTEX_WAKE_PRIVATE, 1) = 1
ppoll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, NULL, NULL, 8) = 1 ([{fd=7, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 512)        = 8
#
rt_sigprocmask(SIG_BLOCK, NULL, [BUS USR1 ALRM IO], 8) = 0
mmap(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0bc85eb000
mprotect(0x7f0bc85eb000, 4096, PROT_NONE) = 0
rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], [BUS USR1 ALRM IO], 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [BUS USR1 ALRM IO], 8) = 0
mmap(NULL, 1052672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0bc84ea000
mprotect(0x7f0bc84ea000, 4096, PROT_NONE) = 0
rt_sigprocmask(SIG_SETMASK, [BUS USR1 ALRM IO], [BUS USR1 ALRM IO], 8) = 0
futex(0x565202a0fd78, FUTEX_WAKE_PRIVATE, 1) = 1
ppoll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, NULL, NULL, 8^C) = ? ERESTARTNOHAND (To be restarted if no handler)
strace: Process 12321 detached
root@storage:~#

bisection status:

  • bug exists upstream
  • bug was introduced inbetween the branches stable-2.12 and stable-3.0
  • works on tag v3.0.0-rc1
  • broken with tag v3.0.0
  • bug introduced in commit 34fa110e424e9a6a9b7e0274c3d4bfee766eb7ed
  • bug fixed upstream between v3.1.0 and v4.0.0
  • fixed in c9fdcf202f19fc2acdcb1ee0522ff5d61bf8c906 (part of https://patchwork.kernel.org/cover/10865751/)

bug report: https://bugs.launchpad.net/cloud-archive/+bug/1895487

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment