systemd: mount units fail with "Mount process finished, but there is no mount."

[jcg190701]

systemd version the issue has been seen with

[root@fedora ~]# systemctl --version
systemd 250 (v250.3-8.fc36)
+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS
+FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK +XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified

Used distribution

Fedora release 36 (Thirty Six)

Linux kernel version used (uname -a)

[root@fedora ~]# uname -a
Linux fedora 5.17.5-300.fc36.x86_64 #1 SMP PREEMPT Thu Apr 28 15:51:30 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

CPU architecture issue was seen on

x86_64

Expected behaviour you didn't see

mounts work

Unexpected behaviour you saw

Mounting units fail with "Mount process finished, but there is no mount.".
It's hard to reproduce with 'systemctl daemon-reload' after #10872 , but it's easy to reproduce with 'systemctl daemon-reexec'.

× root-test.mount - mount unit for test
     Loaded: loaded (/proc/self/mountinfo; static)
     Active: failed (Result: protocol) since Tue 2022-06-21 08:38:28 EDT; 4s ago
      Where: /root/test
       What: /dev/loop0
        CPU: 3ms

Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Child 3065 belongs to root-test.mount.
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Mount process exited, code=exited, status=0/SUCCESS (success)
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Mount process finished, but there is no mount.
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Failed with result 'protocol'.
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Changed mounting -> failed
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Failed to delete cgroup entry from LSM BPF map: No such file or directory
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Job 2039 root-test.mount/start finished, result=failed
Jun 21 08:38:28 fedora systemd[1]: Failed to mount root-test.mount - mount unit for test.
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Unit entered failed state.
Jun 21 08:38:28 fedora systemd[1]: root-test.mount: Consumed 3ms CPU time.

Steps to reproduce the problem

1. dd if=/dev/zero of=device_file.img bs=1024 count=20000
2. mkfs.ext4 device_file.img;mkdir -p /root/test
3. add test.sh and root-test.mount
4. systemd-analyze set-log-level debug
5. run test.sh

[root@fedora ~]# cat test.sh 
#!/bin/bash
random_sleep() {
    local long
    long="${1-2}"
    sleep $(bc <<< "scale=4; $long*$RANDOM/327670")
    #    echo $(bc <<< "scale=4; $long*$RANDOM/327670")
}

while true
do
    systemctl start root-test.mount & random_sleep
    systemctl daemon-reexec
    sleep 5
    systemctl status root-test.mount >> /root/mount.log
    grep "but there is no mount" /root/mount.log
    if [ $? -eq 0 ]; then
           break
    fi
    systemctl stop root-test.mount
    sleep 2
done
[root@fedora ~]#
[root@fedora ~]# cat /etc/systemd/system/root-test.mount 
[Unit]
Description=mount unit for test
[Mount]
What=/root/device_file.img
Where=/root/test
Type=ext4
Options=nodev
[root@fedora ~]#

[Geass-LL]

When execting systemctl daemon-reexec, the mount monitor will be freed, systemd doesn't know the changes of /proc/self/mountinfo before the monitor is reestablished. Maybe we should recompare the mounting state and /proc/self/mountinfo after reexecuting?

[jcg190701]

When execting systemctl daemon-reexec, the mount monitor will be freed, systemd doesn't know the changes of /proc/self/mountinfo before the monitor is reestablished. Maybe we should recompare the mounting state and /proc/self/mountinfo after reexecuting?

What you're talking about may be right. systemd may not run mount_dispatch_io to change mount state if mount monitor is freed.