Bug 1379396

Description of problem:


Some machines fail to provision and die early in Anaconda. After troubleshooting session it turns out that, initially we see following failure and error message on the console:


dracut-initqueue[1131]: /sbin/dmsquash-live-root: line 73: [: too many arguments
dracut-initqueue[1131]: modprobe: FATAL: Module udevadm not found.


and it all boils down to /sbin/dmsquash-live-root and line 55 in function det_img_fs() which has:


53  # determine filesystem type for a filesystem image
54  det_img_fs() {
55      udevadm settle
56      blkid -s TYPE -u noraid -o value "$1"
57  }


However on our hardware default timeout of 120 seconds for udevadm settle is not long enough and udevadm fails with:


dracut:/# udevadm settle
udevadm settle - timeout of 120 seconds reached, the event queue contains:
/sys/devices/pci0000:00/0000:00:01.0 (4729)
/sys/devices/pci0000:00/0000:00:01.0/0000:01:00.0 (4730)
/sys/devices/pci0000:00/0000:00:01.0/pci_bus/0000:01 (4731)


and that output is (probably) returned from det_img_fs() via stdout, assigned to $fstype shell variable:


66      # check filesystem type and handle accordingly
67      fstype=$(det_img_fs $livedev)


and later in the code used as:


73      [ -e /sys/fs/$fstype ] || modprobe $fstype


we can see that $fstype is not quoted so that would explain earlier error:

dracut-initqueue[1131]: /sbin/dmsquash-live-root: line 73: [: too many arguments



and also later error:



dracut-initqueue[1131]: modprobe: FATAL: Module udevadm not found.


Few minutes waiting on the console we see following message from kernel:



[  378.229461] megaraid_sas 0000:01:00.0: megasas: FW restarted successfully from megasas_init_fw!
[  408.280719] megasas: Waiting for FW to come to ready state


So I think udevadm settle may need a few minutes to finish. I this bug report I would like to make sure that udevadm output is never printed to stdout, but to stderr, and did in our production environment this:


% diff -u dmsquash-live-root.orig dmsquash-live-root
--- dmsquash-live-root.orig     2016-09-20 13:57:25.308146153 -0700
+++ dmsquash-live-root  2016-09-20 13:53:01.791324083 -0700
@@ -52,7 +52,7 @@
 # determine filesystem type for a filesystem image
 det_img_fs() {
-    udevadm settle
+    udevadm settle >&2
     blkid -s TYPE -u noraid -o value "$1"
 }

and that fixed the problem for us. Actually it made for us visible and obvious that problem was with the hardware not with Anaconda itself, but I sill think it would be beneficial for Anaconda (dracut) to redirect `udevadm settle` output to stderr to make sure output from det_img_fs() function is always only from blkid command.

Version-Release number of selected component (if applicable):

it's dracut inside anaconda 21.48.22.56-1

How reproducible:

start anaconda with devices which make udevadm settle to run over default 120 seconds timeout, so udevadm will print to stdout error about timeout


Steps to Reproduce:
1. just start kickstart imaging
2. wait to problem to occur, but it needs to happen with specific hardware to make udevadm settle to be slow

Actual results:

Imaging fails with

dracut-initqueue[1131]: /sbin/dmsquash-live-root: line 73: [: too many arguments
dracut-initqueue[1131]: modprobe: FATAL: Module udevadm not found.

Expected results:

Imaging should not have above error.

Additional info:

Let me know anything you may need to know. I've checked git repo at:

https://github.com/dracutdevs/dracut/blob/master/modules.d/90dmsquash-live/dmsquash-live-root.sh

and function det_img_fs has udevadm settle on line 59 without stderr redirection so I believe the problem is also there. However I don't know which repo is the official dracut repo, so not sure where should I really report this bug. I'm happy to report this also to upstream.