Bug#567019: kpartx: multipath partition devices are missing

Wed Jan 27 19:26:14 UTC 2010

Ferenc Wagner <wferi at niif.hu> writes:

> Guido Günther <agx at sigxcpu.org> writes:
>
>> Could you add a "sleep 10" at the end of the multipath local-top
>> initramfs script?  It's possible that lvm "grabs" the sd* devices before
>> multipath had a chance to assemble the multipath maps. That would at
>> least look like the above.
>
> Sure I could, but I think I already avoided that by putting
>
>   filter = [ "a|^/dev/mapper/nfs2$|", "r/.*/" ]
>
> in /etc/lvm/lvm.conf (and propagated that into the initramfs).

Now I put this to the end of scripts/local-top/multipath:

if [ ! -e /dev/mapper/nfs2 ]; then
    echo "Running kpartx for #567019..."
    kpartx -a /dev/mapper/nfs
    ls -l /dev/mapper
fi

and got something weird during boot (now with the kernel messages
intermingled):

Begin: Mounting root file system[   29.928121] device-mapper: uevent: version 1.0.3
 ... Begin: Runn[   29.956537] device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel at redhat.com
ing /scripts/loc[   30.017966] device-mapper: multipath: version 1.1.0 loaded
al-top ... Begin: Loading multipath modules ... Success: loaded [   30.084789] sd 1:0:0:0: [sdb] Device not ready
module dm-multip[   30.115954] sd 1:0:0:0: [sdb] ath.
Failure: fResult: hostbyte=DID_OK driverbyte=DRIVER_SENSE
ailed to load mo[   30.175207] sd 1:0:0:0: [sdb] dule dm-emc.
doSense Key : Not Ready ne.
Begin: Disc[current] overing multipat
hs ... [   30.243319] sd 1:0:0:0: [sdb] Add. Sense: Logical unit not ready, manual intervention required
[   30.298463] sd 1:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 00 00 00 01 00 00
[   30.339561] end_request: I/O error, dev sdb, sector 0
[   30.369751] __ratelimit: 63 callbacks suppressed
[   30.397332] Buffer I/O error on device sdb, logical block 0
[   30.430638] Buffer I/O error on device sdb, logical block 1
[   30.463942] Buffer I/O error on device sdb, logical block 2
[   30.497245] Buffer I/O error on device sdb, logical block 3
[   30.530547] Buffer I/O error on device sdb, logical block 4
[   30.563851] Buffer I/O error on device sdb, logical block 5
[   30.597154] Buffer I/O error on device sdb, logical block 6
[   30.630456] Buffer I/O error on device sdb, logical block 7
[   30.663760] Buffer I/O error on device sdb, logical block 8
[   30.697062] Buffer I/O error on device sdb, logical block 9
[   30.730597] sd 1:0:0:0: [sdb] Device not ready
[   30.757154] sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[   30.799827] sd 1:0:0:0: [sdb] Sense Key : Not Ready [current] 
[   30.834746] sd 1:0:0:0: [sdb] Add. Sense: Logical unit not ready, manual intervention required
[   30.886277] sd 1:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 00 00 00 00 08 00
[   30.927477] end_request: I/O error, dev sdb, sector 0
[   30.970486] sd 0:0:0:0: [sdc] Device not ready
[   30.974918] sd 1:0:0:0: [sdb] Device not ready
[   30.974922] sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[   30.974926] sd 1:0:0:0: [sdb] Sense Key : Not Ready [current] 
[   30.974930] sd 1:0:0:0: [sdb] Add. Sense: Logical unit not ready, manual intervention required
[   30.974936] sd 1:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 00 00 00 00 08 00
[   30.974944] end_request: I/O error, dev sdb, sector 0
[   30.975107] sd 1:0:0:0: emc: detected Clariion CX3-40f, flags 0
[   30.975208] sd 1:0:0:0: emc: connected to SP A Port 2 (bound, default SP B)
[   31.300854] sd 0:0:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[   31.343526] sd 0:0:0:0: [sdc] Sense Key : Not Ready [current] 
[   31.378453] sd 0:0:0:0: [sdc] Add. Sense: Logical unit not ready, manual intervention required
[   31.429983] sd 0:0:0:0: [sdc] CDB: Read(10): 28 00 00 00 00 00 00 01 00 00
[   31.471130] end_request: I/O error, dev sdc, sector 0
[   31.501383] sd 0:0:0:0: emc: detected Clariion CX3-40f, flags 0
[   31.536790] sd 0:0:0:0: [sdc] Device not ready
[   31.536969] sd 0:0:0:0: emc: connected to SP A Port 3 (bound, default SP B)
[   31.604956] sd 0:0:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[   31.647627] sd 0:0:0:0: [sdc] Sense Key : Not Ready [current] 
[   31.682545] sd 0:0:0:0: [sdc] Add. Sense: Logical unit not ready, manual intervention required
[   31.734072] sd 0:0:0:0: [sdc] CDB: Read(10): 28 00 00 00 00 00 00 00 08 00
[   31.775168] end_request: I/O error, dev sdc, sector 0
[   31.805381] sd 1:0:1:0: emc: detected Clariion CX3-40f, flags 0
[   31.840907] sd 1:0:1:0: emc: connected to SP B Port 2 (owned, default SP B)
[   31.882657] sd 0:0:1:0: emc: detected Clariion CX3-40f, flags 0
[   31.918137] sd 0:0:1:0: emc: connected to SP B Port 3 (owned, default SP B)
[   31.959767] emc: device handler registered
[   31.986292] device-mapper: multipath round-robin: version 1.0.0 loaded
libdevmapper: li[   32.027834] sd 0:0:1:0: emc: at SP B Port 3 (owned, default SP B)
bdm-common.c(462[   32.071062] sd 1:0:1:0: emc: at SP B Port 2 (owned, default SP B)
): Created /dev/mapper/nfs
done.
Running kpartx for #567019...
crw-rw----    1 0        0         10,  58 Jan 27 18:56 control
brw-rw----    1 0        0        254,   0 Jan 27 18:57 nfs
brw-rw----    1 0        6        254,   1 Jan 27 18:57 nfs1
br[   32.245554] SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
w-rw----    1 0 [   32.306949] SGI XFS Quota Management subsystem
       6        254,   2 Jan 27 18:57 nfs2
done[   32.358297] XFS mounting filesystem dm-3
.
Begin: Running /scripts/local-premount ... done.
Begin: Running /scripts/local-bottom ... done.
done.
Begin: Running /scripts/init-bottom ... done.
INIT: version 2.86 booting
Starting the hotplug events dispatcher: udevd[   33.270664] udev: starting version 150
.
Synthesizing the initial hotplug events...done.
Waiting for /dev to be fully populated...[   33.393408] processor LNXCPU:00: registered as cooling_device0
[   33.428935] processor LNXCPU:01: registered as cooling_device1
[   33.465075] processor LNXCPU:02: registered as cooling_device2
[   33.500260] processor LNXCPU:03: registered as cooling_device3
[   33.585472] input: PC Speaker as /devices/platform/pcspkr/input/input5
[   33.597303] EDAC MC: Ver: 2.1.0 Jan 10 2010
[   33.654614] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[   33.695775] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[   33.741115] EDAC e752x: tolm = c0000, remapbase = ffc000, remaplimit = 0
[   33.781203] intel_rng: FWH not detected
[   33.804203] EDAC MC0: Giving out device to 'e752x_edac' 'E7520': DEV 0000:00:00.0
[   33.849132] EDAC PCI0: Giving out device to module 'e752x_edac' controller 'EDAC PCI controller': DEV '0000:00:00.0' (POLLED)
[   33.935508] i801_smbus 0000:00:1f.3: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[   34.091577] Error: Driver 'pcspkr' is already registered, aborting...

udevadm settle - timeout of 180 seconds reached, the event queue contains:
  /sys/devices/pci0000:00/0000:00:03.0/0000:04:00.0/0000:06:01.0/host0/rport-0:0-0/target0:0:0/0:0:0:0/block/sdc (10657)
  /sys/devices/pci0000:00/0000:00:03.0/0000:04:00.0/0000:06:01.1/host1/rport-1:0-0/target1:0:0/1:0:0:0/block/sdb (10658)
done (timeout).
Checking root file system...fsck from util-linux-ng 2.16.2
[  213.621848] loop: module loaded

done.
[...]

After this, the system booted up normally.  I can't interpret the
udevadm settle timeout message, but it indeed turned up after 3 minutes
of delay, as you can see from the kernel timestamps.  /dev/sd[bc] are
present, FWIW; they are the inactive paths...
-- 
Puzzled,
Feri.