From f58b96d3e8d1cb0dd3666bc74fa673918b586612 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Mon, 14 Sep 2020 17:58:03 +0200 Subject: [PATCH] test-mountpointutil-util: do not assert in test_mnt_id() https://bugzilla.redhat.com/show_bug.cgi?id=1803070 I *think* this a kernel bug: the mnt_id as listed in /proc/self/mountinfo is different than the one we get from /proc/self/fdinfo/. This only matters when both statx and name_to_handle_at are unavailable and we hit the fallback path that goes through fdinfo: (gdb) !uname -r 5.6.19-200.fc31.ppc64le (gdb) !cat /proc/self/mountinfo 697 664 253:0 /var/lib/mock/fedora-31-ppc64le/root / rw,relatime shared:298 master:1 - xfs /dev/mapper/fedora_rh--power--vm14-root rw,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota 698 697 253:0 /var/cache/mock/fedora-31-ppc64le/yum_cache /var/cache/yum rw,relatime shared:299 master:1 - xfs /dev/mapper/fedora_rh--power--vm14-root rw,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota 699 697 253:0 /var/cache/mock/fedora-31-ppc64le/dnf_cache /var/cache/dnf rw,relatime shared:300 master:1 - xfs /dev/mapper/fedora_rh--power--vm14-root rw,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota 700 697 0:32 /mock-selinux-plugin.7me9bfpi /proc/filesystems rw,nosuid,nodev shared:301 master:18 - tmpfs tmpfs rw,seclabel <========================================================== 701 697 0:41 / /sys ro,nosuid,nodev,noexec,relatime shared:302 - sysfs sysfs ro,seclabel 702 701 0:21 / /sys/fs/selinux ro,nosuid,nodev,noexec,relatime shared:306 master:8 - selinuxfs selinuxfs rw 703 697 0:42 / /dev rw,nosuid shared:303 - tmpfs tmpfs rw,seclabel,mode=755 704 703 0:43 / /dev/shm rw,nosuid,nodev shared:304 - tmpfs tmpfs rw,seclabel 705 703 0:45 / /dev/pts rw,nosuid,noexec,relatime shared:307 - devpts devpts rw,seclabel,gid=5,mode=620,ptmxmode=666 706 703 0:6 /btrfs-control /dev/btrfs-control rw,nosuid shared:308 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 707 703 0:6 /loop-control /dev/loop-control rw,nosuid shared:309 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 708 703 0:6 /loop0 /dev/loop0 rw,nosuid shared:310 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 709 703 0:6 /loop1 /dev/loop1 rw,nosuid shared:311 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 710 703 0:6 /loop10 /dev/loop10 rw,nosuid shared:312 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 711 703 0:6 /loop11 /dev/loop11 rw,nosuid shared:313 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 712 703 0:6 /loop2 /dev/loop2 rw,nosuid shared:314 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 713 703 0:6 /loop3 /dev/loop3 rw,nosuid shared:315 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 714 703 0:6 /loop4 /dev/loop4 rw,nosuid shared:316 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 715 703 0:6 /loop5 /dev/loop5 rw,nosuid shared:317 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 716 703 0:6 /loop6 /dev/loop6 rw,nosuid shared:318 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 717 703 0:6 /loop7 /dev/loop7 rw,nosuid shared:319 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 718 703 0:6 /loop8 /dev/loop8 rw,nosuid shared:320 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 719 703 0:6 /loop9 /dev/loop9 rw,nosuid shared:321 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755 720 697 0:44 / /run rw,nosuid,nodev shared:305 - tmpfs tmpfs rw,seclabel,mode=755 721 720 0:25 /systemd/nspawn/propagate/9cc8a155d0244558b273f773d2b92142 /run/systemd/nspawn/incoming ro master:12 - tmpfs tmpfs rw,seclabel,mode=755 722 697 0:32 /mock-resolv.dvml91hp /etc/resolv.conf rw,nosuid,nodev shared:322 master:18 - tmpfs tmpfs rw,seclabel 725 697 0:47 / /proc rw,nosuid,nodev,noexec,relatime shared:323 - proc proc rw 603 725 0:47 /sys /proc/sys ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw 604 725 0:44 /systemd/inaccessible/reg /proc/kallsyms ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755 605 725 0:44 /systemd/inaccessible/reg /proc/kcore ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755 606 725 0:44 /systemd/inaccessible/reg /proc/keys ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755 607 725 0:44 /systemd/inaccessible/reg /proc/sysrq-trigger ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755 608 725 0:44 /systemd/inaccessible/reg /proc/timer_list ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755 609 725 0:47 /bus /proc/bus ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw 610 725 0:47 /fs /proc/fs ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw 611 725 0:47 /irq /proc/irq ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw 612 725 0:47 /scsi /proc/scsi ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw 613 703 0:46 / /dev/mqueue rw,nosuid,nodev,noexec,relatime shared:324 - mqueue mqueue rw,seclabel 614 701 0:26 / /sys/fs/cgroup rw,nosuid,nodev,noexec,relatime shared:325 - cgroup2 cgroup rw,seclabel,nsdelegate 615 603 0:44 /.#proc-sys-kernel-random-boot-id4fbdce67af46d1c2//deleted /proc/sys/kernel/random/boot_id ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755 616 725 0:44 /.#proc-sys-kernel-random-boot-id4fbdce67af46d1c2//deleted /proc/sys/kernel/random/boot_id rw,nosuid,nodev shared:305 - tmpfs tmpfs rw,seclabel,mode=755 617 725 0:44 /.#proc-kmsg5b7a8bcfe6717139//deleted /proc/kmsg rw,nosuid,nodev shared:305 - tmpfs tmpfs rw,seclabel,mode=755 The test process does name_to_handle_at("/proc/filesystems") which returns -EOPNOTSUPP, and then openat(AT_FDCWD, "/proc/filesystems") which returns 4, and then read(open("/proc/self/fdinfo/4", ...)) which gives "pos:\t0\nflags:\t012100000\nmnt_id:\t725\n" and the "725" is clearly inconsistent with "700" in /proc/self/mountinfo. We could either drop the fallback path (and fail name_to_handle_at() is not avaliable) or ignore the error in the test. Not sure what is better. I think this issue only occurs sometimes and with older kernels, so probably continuing with the current flaky implementation is better than ripping out the fallback. Another strace: writev(2, [{iov_base="mnt ids of /proc/sys is 603", iov_len=27}, {iov_base="\n", iov_len=1}], 2mnt ids of /proc/sys is 603 ) = 28 name_to_handle_at(AT_FDCWD, "/", {handle_bytes=128 => 12, handle_type=129, f_handle=0x52748401000000008b93e20d}, [697], 0) = 0 writev(2, [{iov_base="mnt ids of / is 697", iov_len=19}, {iov_base="\n", iov_len=1}], 2mnt ids of / is 697 ) = 20 name_to_handle_at(AT_FDCWD, "/proc/kcore", {handle_bytes=128 => 12, handle_type=1, f_handle=0x92ddcfcd2e802d0100000000}, [605], 0) = 0 writev(2, [{iov_base="mnt ids of /proc/kcore is 605", iov_len=29}, {iov_base="\n", iov_len=1}], 2mnt ids of /proc/kcore is 605 ) = 30 name_to_handle_at(AT_FDCWD, "/dev", {handle_bytes=128 => 12, handle_type=1, f_handle=0x8ae269160c802d0100000000}, [703], 0) = 0 writev(2, [{iov_base="mnt ids of /dev is 703", iov_len=22}, {iov_base="\n", iov_len=1}], 2mnt ids of /dev is 703 ) = 23 name_to_handle_at(AT_FDCWD, "/proc/filesystems", {handle_bytes=128}, 0x7fffe36ddb84, 0) = -1 EOPNOTSUPP (Operation not supported) openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 4 openat(AT_FDCWD, "/proc/self/fdinfo/4", O_RDONLY|O_CLOEXEC) = 5 fstat(5, {st_mode=S_IFREG|0400, st_size=0, ...}) = 0 fstat(5, {st_mode=S_IFREG|0400, st_size=0, ...}) = 0 read(5, "pos:\t0\nflags:\t012100000\nmnt_id:\t725\n", 2048) = 36 read(5, "", 1024) = 0 close(5) = 0 close(4) = 0 writev(2, [{iov_base="mnt ids of /proc/filesystems are 700, 725", iov_len=41}, {iov_base="\n", iov_len=1}], 2mnt ids of /proc/filesystems are 700, 725 ) = 42 writev(2, [{iov_base="the other path for mnt id 725 is /proc", iov_len=38}, {iov_base="\n", iov_len=1}], 2the other path for mnt id 725 is /proc ) = 39 writev(2, [{iov_base="Assertion 'path_equal(p, t)' failed at src/test/test-mountpoint-util.c:94, function test_mnt_id(). Aborting.", iov_len=108}, {iov_base="\n", iov_len=1}], 2Assertion 'path_equal(p, t)' failed at src/test/test-mountpoint-util.c:94, function test_mnt_id(). Aborting. ) = 109 rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0 getpid() = 20 gettid() = 20 tgkill(20, 20, SIGABRT) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 --- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=20, si_uid=0} --- +++ killed by SIGABRT (core dumped) +++ --- src/test/test-mountpoint-util.c | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/src/test/test-mountpoint-util.c b/src/test/test-mountpoint-util.c index 30b00ae4d8b7..ffe5144b04ae 100644 --- a/src/test/test-mountpoint-util.c +++ b/src/test/test-mountpoint-util.c @@ -89,8 +89,12 @@ static void test_mnt_id(void) { /* The ids don't match? If so, then there are two mounts on the same path, let's check if * that's really the case */ char *t = hashmap_get(h, INT_TO_PTR(mnt_id2)); - log_debug("the other path for mnt id %i is %s\n", mnt_id2, t); - assert_se(path_equal(p, t)); + log_debug("Path for mnt id %i from /proc/self/mountinfo is %s\n", mnt_id2, t); + + if (!path_equal(p, t)) + /* Apparent kernel bug in /proc/self/fdinfo */ + log_warning("Bad mount id given for %s: %d, should be %d", + p, mnt_id2, mnt_id); } }