From 4ad39b0531f550cde6e01df0801f177c08514c8b Mon Sep 17 00:00:00 2001

From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= <zbyszek@in.waw.pl>

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</dev/pts/0>, [{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</dev/pts/0>, [{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</dev/pts/0>, [{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</dev/pts/0>, [{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</proc/filesystems>

openat(AT_FDCWD, "/proc/self/fdinfo/4", O_RDONLY|O_CLOEXEC) = 5</proc/20/fdinfo/4>

fstat(5</proc/20/fdinfo/4>, {st_mode=S_IFREG|0400, st_size=0, ...}) = 0

fstat(5</proc/20/fdinfo/4>, {st_mode=S_IFREG|0400, st_size=0, ...}) = 0

read(5</proc/20/fdinfo/4>, "pos:\t0\nflags:\t012100000\nmnt_id:\t725\n", 2048) = 36

read(5</proc/20/fdinfo/4>, "", 1024)    = 0

close(5</proc/20/fdinfo/4>)             = 0

close(4</proc/filesystems>)             = 0

writev(2</dev/pts/0>, [{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</dev/pts/0>, [{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</dev/pts/0>, [{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

Resolves: #1910425

---

 src/test/test-mount-util.c | 8 +++++++-

 1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/src/test/test-mount-util.c b/src/test/test-mount-util.c

index c10e1681fb..991d165fc3 100644

--- a/src/test/test-mount-util.c

+++ b/src/test/test-mount-util.c

@@ -74,7 +74,13 @@ 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 */

-                assert_se(path_equal_ptr(hashmap_get(h, INT_TO_PTR(mnt_id2)), p));

+                char *t = hashmap_get(h, INT_TO_PTR(mnt_id2));

+                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);

         }

         hashmap_free_free(h);