fix(base): don't wait infinitely for a device with non-persistent name

[coiby]

Currently, dracut will wait finitely for a block device e.g. /dev/sda2
when users use "dracut --add-device /dev/sda2". However, /dev/sda2 is
not a persistant name and it can show as a different name and kdump can
fail [1] as dracut will wait forever for /dev/sda2.

Commit c79fc8f ("fix(dracut): rework timeout for devices added
via --mount and --add-device") already sets infinite timeout for
the underlying persistent device. There is no need to also set infinite
timeout for non-persistent device name. Removing the redundant wait can
automatically resolve the case where a device name changes.

[1] rhkdump/kdump-utils#121

Reported-by: Alex Burmashev alexander.burmashev@oracle.com
Reported-by: Harshvardhan Jha harshvardhan.j.jha@oracle.com
Fixes: c79fc8f ("fix(dracut): rework timeout for devices added via --mount and --add-device")

Checklist

• I have tested it locally
• I have reviewed and updated any documentation if relevant
• I am providing new code and test(s) for it

[aafeijoo-suse]

In fact c79fc8f fixed some bugs reported to openSUSE kump and their use of --add-device (CC @jiribohac, this was bsc#1231792). For example, for LVM devices added via --add-device, dracut uses /dev/vg/lv while systemd uses /dev/vg-lv, so systemd does not see the timeout.conf file under /etc/systemd/system/dev-lv-vg/. The result is the default systemd timeout of 90 seconds applies instead of the intended infinity and kdump ends up failing. So reverting this commit to fix the use of --add-device in RH kdump, would bring back again problems in openSUSE kdump. @jiribohac, maybe you can give your opinion here.

BTW, don't you know the UUID of the device to use --add-device with a persistent name instead?

[aafeijoo-suse]

Forget my previous comment, I overlooked the fact that we will continue waiting for the device to become available using its persistent path. So, this should be ok.

[coiby]

Forget my previous comment, I overlooked the fact that we will continue waiting for the device to become available using its persistent path. So, this should be ok.

Thanks for reviewing the patch! I just pushed a new version. The is no code change. I only improved the commit message and hopefully it can bring more clarity.

[bdrung]

There is a merge commit in the PR. Can you rebase your branch on main to drop the merge commit?

[jiribohac]

I am quite sure this change will reintroduce the problem fixed by commit c79fc8f.

Your problem is calling dracut with --mount (or --add-device) with a non-persistent device name.
Dracut does not convert this into a persistent name and puts the device into the fstab exactly as supplied to the --mount option. If the device name changes on the next boot, this will fail, because the initrd fstab will be wrong. You need to supply a persistent device name to --mount anyway - not only to avoid this timeout but also to make the mount work.

The problem fixed with c79fc8f is:
the .timeout created by wait_for_dev during boot does not always correspond to the device name in the initrd fstab, and thus to the systemd mount unit created by the systemd fstab generator. So the systemd mount unit may time out after 90s (the default timeout), instead of waiting indefinitely.

The scenario when this problem was found:
dracut is run with: --mount '/dev/mapper/vg-lvol0 /kdump/mnt/var/crash ext3 rw,relatime'

The resulting initrd has:
/etc/fstab containing "/dev/mapper/vg-lvol0 /kdump/mnt/var/crash ext3 rw,relatime 0 2"
etc/cmdline.d/90lvm.conf containing "rd.lvm.lv=vg/lvol0"

During boot dracut calls:
/lib/dracut/hooks/cmdline/30-parse-lvm.sh@15(source): wait_for_dev -n /dev/vg/lvol0
creating /etc/systemd/system/dev-vg-lvol0.device.d/timeout.conf

We want to wait forever for the devices.
But the result is only a 90s wait, which may fail on a complicated storage setup:

After 90 seconds systemd prints "[ TIME ] Timed out waiting for device /dev/mapper/
vg-lvol0" and starts the emergency shell.

systemctl show /dev/mapper/vg-lvol0 prints "JobRunningTimeoutUSec=1min 30s"
systemctl show /dev/vg/lvol0 prints "JobRunningTimeoutUSec=infinity"

systemd uses /dev/mapper/vg-lvol0, because that is what is found in the fstab - thus timing out the mount unit after 90 seconds.

We need to set the timeout for the device as configured in the fstab.

[coiby]

I am quite sure this change will reintroduce the problem fixed by commit c79fc8f.

Your problem is calling dracut with --mount (or --add-device) with a non-persistent device name. Dracut does not convert this into a persistent name and puts the device into the fstab exactly as supplied to the --mount option. If the device name changes on the next boot, this will fail, because the initrd fstab will be wrong. You need to supply a persistent device name to --mount anyway - not only to avoid this timeout but also to make the mount work.

Thanks for letting me know that dracut currently doesn't convert a disk name to a persistent name when writing to /etc/fstab! Fortunately, in the case of rhkdump/kdump-utils#121, --add-device is used so it won't write to fstab.

I'm bit confused with c79fc8f. Because the commit message explicitly mentioned --mount "/dev/sda1 ..." which makes me believe it's going to support adding a device without persistent name.

The problem fixed with c79fc8f is: the .timeout created by wait_for_dev during boot does not always correspond to the device name in the initrd fstab, and thus to the systemd mount unit created by the systemd fstab generator. So the systemd mount unit may time out after 90s (the default timeout), instead of waiting indefinitely.

The scenario when this problem was found: dracut is run with: --mount '/dev/mapper/vg-lvol0 /kdump/mnt/var/crash ext3 rw,relatime'

The resulting initrd has: /etc/fstab containing "/dev/mapper/vg-lvol0 /kdump/mnt/var/crash ext3 rw,relatime 0 2" etc/cmdline.d/90lvm.conf containing "rd.lvm.lv=vg/lvol0"

During boot dracut calls: /lib/dracut/hooks/cmdline/30-parse-lvm.sh@15(source): wait_for_dev -n /dev/vg/lvol0 creating /etc/systemd/system/dev-vg-lvol0.device.d/timeout.conf

We want to wait forever for the devices. But the result is only a 90s wait, which may fail on a complicated storage setup:

After 90 seconds systemd prints "[ TIME ] Timed out waiting for device /dev/mapper/ vg-lvol0" and starts the emergency shell.

systemctl show /dev/mapper/vg-lvol0 prints "JobRunningTimeoutUSec=1min 30s" systemctl show /dev/vg/lvol0 prints "JobRunningTimeoutUSec=infinity"

systemd uses /dev/mapper/vg-lvol0, because that is what is found in the fstab - thus timing out the mount unit after 90 seconds.

We need to set the timeout for the device as configured in the fstab.

Thanks for explaining the problem that c79fc8f tried to address in details! In your given example, you want to wait infinitely for /dev/mapper/vg-lvol0. But it seems even before commit c79fc8f, dracut already waits infinitely for /dev/mapper/vg-lvol0 because /dev/mapper/vg-lvol0 is already a persistent name,

# source /usr/lib/dracut/dracut-functions.sh
# get_persistent_dev /dev/mapper/vg-lvol0 
/dev/mapper/vg-lvol0

And if we still require users to use persistent device name when using --mount/--add-device, calling wait_for_device twice (one for the specified device and the other for the underlying persistent device name) doesn't seem to make sense to me.

So if I miss anything, can you point it out to help me understand the commit better? Thanks!

[coiby]

There is a merge commit in the PR. Can you rebase your branch on main to drop the merge commit?

Thanks for the reminder! I didn't realize that Github will merge the main branch to update my branch. The merge commit is dropped now.

[aafeijoo-suse]

After reading Jiri's comment now I remember the issue. As the commit message says:

Currently, dracut adds a systemd dropin that sets an infinite timeout _only_ for
the underlying persistent devices...
...
This can cause a problem if a user application expects to mount /dev/sda1 in the
initrd (that's why it was explicitly added `--mount "/dev/sda1 ..."`)

The problem is the opposite of what you want to fix. The idea was that if a user configures a device with a specific name via --mount or --add-device, dracut has to wait for that name to appear, and not only for the underlying persistent name.

[jiribohac]

And if we still require users to use persistent device name when using --mount/--add-device, calling wait_for_device twice (one for the specified device and the other for the underlying persistent device name) doesn't seem to make sense to me.

I also don't understand why we want to wait for the persistent name. I suppose Antonio was afraid of breaking someone else's usecase, because waiting for the persistent name was what happened before the commit.

I just know we need to wait for the device name as supplied to --mount (whether persistent or not), because that is what will end up in the fstab and what systemd will put into its mount unit.

[aafeijoo-suse]

I also don't understand why we want to wait for the persistent name. I suppose Antonio was afraid of breaking someone else's usecase, because waiting for the persistent name was what happened before the commit.

Yes, that was the only reason.

[coiby]

@aafeijoo-suse @jiribohac Thanks for helping me understand more about commit c79fc8f! But I'm still not sure what problem it tries to solve. At least for the issue described in Jiri's comment, I don't see the necessity of that commit because /dev/mapper/vg-lvol0 is a persistent name and dracut before this commit already waits forever for it.

Admittedly, using persistent name can resolve the problem that a block devices change its name as described in rhkdump/kdump-utils#121 (comment). Then why not also using persistent name for the problem that commit c79fc8f tries to resolve?

Btw, today I played with dracut for a while and notice the following things,

• For device specified by --add-device /dev/vdb8, after the corresponding system service times out, dracut itself still waits much longer (32s vs 200s)

[   32.152775] systemd[1]: dev-vdb8.device: Job dev-vdb8.device/start timed out.
[   32.154427] systemd[1]: Timed out waiting for device dev-vdb8.device - /dev/vdb8.
[   32.156072] systemd[1]: dev-vdb8.device: Job dev-vdb8.device/start failed with result 'timeout'.
[   ***] Job dracut-initqueue.service/start running (2min 13s / no limit)
[...
[ ***  ] Job dracut-initqueue.service/start running (2min 14s / no limit)
[  136.751702] dracut-initqueue[535]: Warning: dracut-initqueue: timeout, still waiting for following initqueue hooks:
[  136.757897] dracut-initqueue[535]: Warning: /lib/dracut/hooks/initqueue/finished/devexists-\x2fdev\x2fvdb8.sh: "[ -e "/dev/vdb8" ]"
...
[**    ] Job dracut-initqueue.service/start running (3min 19s / no limit)
[  201.503343] dracut-initqueue[535]: Warning: dracut-initqueue: timeout, still waiting for following initqueue hooks:
[  201.509596] dracut-initqueue[535]: Warning: /lib/dracut/hooks/initqueue/finished/devexists-\x2fdev\x2fvdb8.sh: "[ -e "/dev/vdb8" ]"
[  201.512695] dracut-initqueue[535]: Warning: dracut-initqueue: starting timeout scripts

• For a device specified by --mount /dev/vdb8 /test ext4, we'll be dropped to emergency shell much faster,

[   31.803559] systemd[1]: dev-vdb8.device: Job dev-vdb8.device/start timed out.
[   31.803567] systemd[1]: Timed out waiting for device dev-vdb8.device - /dev/vdb8.
...
[   31.815795] systemd[1]: Dependency failed for test.mount - /test.
[   31.817185] systemd[1]: Dependency failed for local-fs.target - Local File Systems.
[DEPEND] Dependency failed for systemd-fsck@dev-vdb8.service - File System Check on /dev/vdb8.
[   31.820325] systemd[1]: local-fs.target: Job local-fs.target/start failed with result 'dependency'.
[   31.822303] systemd[1]: local-fs.target: Triggering OnFailure= dependencies.
[   31.824523] systemd[1]: test.mount: Job test.mount/start failed with result 'dependency'.
[   31.825968] systemd[1]: Dependency failed for systemd-fsck@dev-vdb8.service - File System Check on /dev/vdb8.
[   31.827641] systemd[1]: systemd-fsck@dev-vdb8.service: Job systemd-fsck@dev-vdb8.service/start failed with result 'dependency'.

I wonder if the second situation captures the essence of the problem that commit c79fc8f tries to resolve. If the answer is yes, maybe we make --mount/--add-device truly support non-persistent name by converting non-persistent name into persistent name and always use persistent name e.g when writing to fstab.

[jiribohac]

* For a device specified by `--mount /dev/vdb8 /test ext4`, we'll be dropped to emergency shell much faster,

[   31.803559] systemd[1]: dev-vdb8.device: Job dev-vdb8.device/start timed out.
[   31.803567] systemd[1]: Timed out waiting for device dev-vdb8.device - /dev/vdb8.
...
[   31.815795] systemd[1]: Dependency failed for test.mount - /test.
[   31.817185] systemd[1]: Dependency failed for local-fs.target - Local File Systems.
[DEPEND] Dependency failed for systemd-fsck@dev-vdb8.service - File System Check on /dev/vdb8.
[   31.820325] systemd[1]: local-fs.target: Job local-fs.target/start failed with result 'dependency'.
[   31.822303] systemd[1]: local-fs.target: Triggering OnFailure= dependencies.
[   31.824523] systemd[1]: test.mount: Job test.mount/start failed with result 'dependency'.
[   31.825968] systemd[1]: Dependency failed for systemd-fsck@dev-vdb8.service - File System Check on /dev/vdb8.
[   31.827641] systemd[1]: systemd-fsck@dev-vdb8.service: Job systemd-fsck@dev-vdb8.service/start failed with result 'dependency'.

I wonder if the second situation captures the essence of the problem that commit c79fc8f tries to resolve.

Yes, exactly. The problem was not that dracut would not wait for the device. The problem was that it does not set up the infinite timeout for the systemd mount unit. So systemd times out and starts the emergency shell, while dracut still waits for the device.

If the answer is yes, maybe we make --mount/--add-device truly support non-persistent name by converting non-persistent name into persistent name and always use persistent name e.g when writing to fstab.

In my example it's not even a matter of persistent vs non-persistent names. But instead of two different persistent names.
/dev/mapper/vg-lvol0 and /dev/vg/lvol0. The crucial point being: we need to wait for and set the timeout for whatever gets written to fstab.

[coiby]

Yes, exactly. The problem was not that dracut would not wait for the device. The problem was that it does not set up the infinite timeout for the systemd mount unit. So systemd times out and starts the emergency shell, while dracut still waits for the device.

Thanks for letting me know the problem is systemd mount unit times out! Then I can dig more into systemd mount unit timeout and also its relationship with systemd device service timeout.

I did some experiments. So far my observations don't support "systemd times out and starts the emergency shell, while dracut still waits for the device".

1. commit c79fc8f doesn't change the timeout configuration of a systemd mount unit, for example, the JobRunningTimeoutUSec is infinity regardless of the commit

# systemctl show  test.mount | grep  Timeout
JobTimeoutUSec=infinity
JobRunningTimeoutUSec=infinity
JobTimeoutAction=none
TimeoutUSec=5min
TimeoutCleanUSec=infinity

2. For the experiment of --mount /dev/vdb8 /test ext4, we are dropped to the emergency shell because of the timeout of systemd device service but not because of the timeout of mount unit
3. I notice a systemd mount unit depends on the systemd device service which means systemd mount unit will only be started if a systemd mount unit has been started successfully. If dracut is still waiting for the device, it means the systemd mount unit is yet to be be started,

# systemctl list-dependencies test.mount
test.mount
○ ├─dev-vdb8.device
● ├─system.slice
○ └─systemd-fsck@dev-vdb8.service

I will rethink about it tomorrow. Meanwhile if you think I miss anything, please let me know, thanks!

[jiribohac]

Thanks for letting me know the problem is systemd mount unit times out! Then I can dig more into systemd mount unit timeout and also its relationship with systemd device service timeout.

I did some experiments. So far my observations don't support "systemd times out and starts the emergency shell, while dracut still waits for the device".

2. For the experiment of `--mount /dev/vdb8 /test ext4`, we are dropped to the emergency shell because of the timeout of systemd device service but not because of the timeout of mount unit

Yes, sorry, I made this inaccurate shortcut! It's the timeout of the device, which the mount unit depends on.
It's the timeout that dracut configures using the set_systemd_timeout_for_dev() function, called from wait_for_dev().

[coiby]

@jiribohac Today I did an experiment to double confirm that the timeout of mount unit won't drop us into the emergency before the device service times out. Then it proves me wrong! In the experiment, the device service is supposed to time out after 45s and the mount unit is supposed to time out after 5s. And after about 7s, I'm dropped to the emergency shell,

[ TIME ] Timed out mounting test.mount - /test.
[DEPEND] Dependency failed for local-fs.target - Local File Systems.
[    6.840035] systemd[1]: test.mount: Job test.mount/start timed out.
[    6.843344] systemd[1]: Timed out mounting test.mount - /test.
[    6.844950] systemd[1]: Dependency failed for local-fs.target - Local File Systems.
[    6.847037] systemd[1]: local-fs.target: Job local-fs.target/start failed with result 'dependency'.
[    6.848911] systemd[1]: local-fs.target: Triggering OnFailure= dependencies.
[    6.850334] systemd[1]: test.mount: Job test.mount/start failed with result 'timeout'.
...
[    6.888208] systemd[1]: Starting emergency.service - Kdump Error Handler...
[    6.907218] kdump[598]: Kdump is using the default log level(3).
[    6.914808] kdump[603]: Executing failure action kdump_emergency_shell
...
[DEPEND] Dependency failed for systemd-fsck@dev-vdb8.service - File System Check on /dev/vdb8.
[   46.829795] systemd[1]: dev-vdb8.device: Job dev-vdb8.device/start timed out.
[   46.834015] systemd[1]: Timed out waiting for device dev-vdb8.device - /dev/vdb8.
[   46.835456] systemd[1]: Dependency failed for systemd-fsck@dev-vdb8.service - File System Check on /dev/vdb8.
[   46.837135] systemd[1]: systemd-fsck@dev-vdb8.service: Job systemd-fsck@dev-vdb8.service/start failed with result 'dependency'.
[   46.838917] systemd[1]: dev-vdb8.device: Job dev-vdb8.device/start failed with result 'timeout'.
kdump:/# systemctl show test.mount | grep Timeout
JobTimeoutUSec=5s
JobRunningTimeoutUSec=5s
JobTimeoutAction=none
TimeoutUSec=5s
TimeoutCleanUSec=infinity
kdump:/# systemctl show dev-vdb8.device | grep Timeout
JobTimeoutUSec=infinity
JobRunningTimeoutUSec=45s
JobTimeoutAction=none

But wait_for_dev indeed won't change the the timeout configuration of a mount unit. So we still don't know how commit c79fc8f resolves the problem.

@aafeijoo-suse according to your comment, bsc#1231792 seems to the be problem. Can you visit the bug and share more details? Thanks!

[jiribohac]

But wait_for_dev indeed will change the the timeout configuration of a mount unit. So we still don't know how commit c79fc8f resolves the problem.

how does wait_for_dev change the mount unit timeout? I can only see it changing the device timeout. The function does not even know the name of the mount unit.
From what I read in man systemd.unit, JobTimeoutSec is "infinity" by default, except for the device units. So there should not be any need to set it for the mount unit.
The c79fc8f commit makes sure it's [also] set for the correct device unit.

[coiby]

But wait_for_dev indeed will change the the timeout configuration of a mount unit. So we still don't know how commit c79fc8f resolves the problem.

how does wait_for_dev change the mount unit timeout? I can only see it changing the device timeout. The function does not even know the name of the mount unit. From what I read in man systemd.unit, JobTimeoutSec is "infinity" by default, except for the device units. So there should not be any need to set it for the mount unit.

Sorry, I made a typo. "wait_for_dev indeed will change the the timeout " should be "wait_for_dev indeed won't change the the timeout".

The c79fc8f commit makes sure it's [also] set for the correct device unit.

At least for the example you gave, /dev/mapper/vg-lvol0 is already an persistent name and dracut before commit c79fc8f already sets infinite timeout for this device service. So I don't there is even a need for commit c79fc8f unless bsc#1231792 is somewhat a different problem.

[coiby]

Hi @aafeijoo-suse and @jiribohac, if possible, can you check bsc#1231792 to help me understand what problem commit c79fc8f tries to resolve? Thanks!

[aafeijoo-suse]

Hi @aafeijoo-suse and @jiribohac, if possible, can you check bsc#1231792 to help me understand what problem commit c79fc8f tries to resolve? Thanks!

It has already been described here: #1844 (comment)

[coiby]

Hi @aafeijoo-suse and @jiribohac, if possible, can you check bsc#1231792 to help me understand what problem commit c79fc8f tries to resolve? Thanks!

It has already been described here: #1844 (comment)

Thanks for confirming #1844 (comment) is exactly bsc#1231792!

What confused me is /dev/mapper/vg-lvol0 is already a persistent device name and I thought wait_for_dev dev/mapper/vg-lvol0 will be called even before commit c79fc8f,

# source /usr/lib/dracut/dracut-functions.sh
# get_persistent_dev /dev/mapper/vg-lvol0 
/dev/mapper/vg-lvol0

Then I downloaded Leap-16.0-Minimal-VM.x86_64-kvm-and-xen.qcow2 to find out what really happens.

It turns out SUSE use persistent_policy=by-uuid,

# source /usr/lib/dracut/dracut-functions.sh
# get_persistent_dev /dev/mapper/vg-lvol0 
/dev/mapper/vg-lvol0

# persistent_policy=by-uuid get_persistent_dev /dev/mapper/vg-lvol0 
/dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc

So before commit c79fc8f, infinite timeout is set for /dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc but not /dev/mapper/vg-lvol0 in SUSE kdump initrd,

# /usr/lib/kdump/load.sh --update
Regenerating kdump initrd ...
++ get_persistent_dev /dev/mapper/vg-lvol0
++ local i _tmp _dev _pol
+++ get_maj_min /dev/mapper/vg-lvol0
+++ local _majmin
+++ local _out
+++ [[ -n /var/tmp/dracut.hoWYLR/majmin_cache ]]
++++ grep -m1 -oE '^/dev/mapper/vg-lvol0 \S+$' /var/tmp/dracut.hoWYLR/majmin_cache
++++ awk '{print $NF}'
+++ _out=253:0
+++ [[ -n 253:0 ]]
+++ echo -n 253:0
++ _dev=253:0
++ '[' -z 253:0 ']'
++ [[ -n by-uuid ]]
++ _pol='/dev/disk/by-uuid/*'
++ for i in $_pol /dev/mapper/* /dev/disk/by-uuid/* /dev/disk/by-label/* /dev/disk/by-partuuid/* /dev/disk/by-partlabel/* /dev/disk/by-id/* /dev/disk/by-path/*
++ [[ -b /dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc ]]
++ [[ /dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc == /dev/mapper/mpath* ]]
+++ get_maj_min /dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc
+++ local _majmin
+++ local _out
+++ [[ -n /var/tmp/dracut.hoWYLR/majmin_cache ]]
++++ grep -m1 -oE '^/dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc \S+$' /var/tmp/dracut.hoWYLR/majmin_cache
++++ awk '{print $NF}'
+++ _out=253:0
+++ [[ -n 253:0 ]]
+++ echo -n 253:0
++ _tmp=253:0
++ '[' 253:0 = 253:0 ']'
++ printf -- %s /dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc
++ return
+ _pdev=/dev/disk/by-uuid/69f27553-5f60-41e8-94a7-51e6b8da79fc
+ set +x

[devkontrol]

needs rebase