Multipath devices take long to initialize during initramfs
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
multipath-tools (Ubuntu) |
Fix Released
|
High
|
Mathieu Trudel-Lapierre | ||
Trusty |
Fix Released
|
High
|
Mathieu Trudel-Lapierre |
Bug Description
[Impact]
Impacts any user of multipath, regardless of release. Users who do not currently see issues may see them on upgrade to a newer version of systemd/udev.
[Test case]
See below. Test case can be summarized as "boot on a multipath system".
[Regression potential]
This changes the behavior on locking devices for multipath, to avoid a deadlock with udev. Since this changes the locking behavior of multipath this may also affect other scripts or applications depending on multipath doing an exclusive lock, so scripts or applications could fail because they acquired a lock on the devices prematurely, before multipath was finished. In most cases this shouldn't happen, as it should be limited to an isolated multipath step in the boot process (in initramfs).
---
Problem: during initramfs, multipath devices takes long to initialize (~30 seconds?)
Symptom:
<...>
Loading, please wait...
<...>
[ 4.492303] device-mapper: multipath: version 1.7.0 loaded
[ 4.643053] random: nonblocking pool is initialized
worker [116] /devices/
worker [117] /devices/
worker [121] /devices/
worker [123] /devices/
<... here's the delay ...>
timeout '/sbin/multipath -v0 /dev/sda'
slow: '/sbin/multipath -v0 /dev/sda' [181]
timeout '/sbin/multipath -v0 /dev/sdb'
slow: '/sbin/multipath -v0 /dev/sdb' [178]
timeout '/sbin/multipath -v0 /dev/sdc'
slow: '/sbin/multipath -v0 /dev/sdc' [180]
timeout '/sbin/multipath -v0 /dev/sdd'
slow: '/sbin/multipath -v0 /dev/sdd' [182]
worker [116] /devices/
seq 1059 '/devices/
worker [117] /devices/
seq 1079 '/devices/
worker [121] /devices/
seq 1069 '/devices/
worker [123] /devices/
seq 1089 '/devices/
worker [116] terminated by signal 9 (Killed)
worker [117] terminated by signal 9 (Killed)
worker [121] terminated by signal 9 (Killed)
worker [123] terminated by signal 9 (Killed)
<...>
<login prompt>
Reason:
When udev starts to handle the block device, it acquires a lock on it, then processes the rules.
Therefore, by the time 'multipath' runs (called in udev rules), the block device is already locked.
For 'multipath' to finish, it must acquire a *exclusive* lock on the block device.
Thus it fails (exclusive mode doesn't succeed with another lock in place).
So it loops, trying again until the lock is acquired.
(messages: "failed to create map (in use)" / "restart multipath configuration process").
Sure enough, it will keep looping.. until killed by time-out (message: "timeout '/sbin/multipath -v0 /dev/sda'").
Only then (after rule-processing) udev releases the lock.
The next call to the 'multipath' command succeeds (out of udev rules, in /scripts/
This happens because, by that time, udev has finished handling all devices (i.e., 'udev settle' in /scripts/
so there's no more the udev worker lock to the underlying block device(s).
Steps to reproduce:
Do a multipath install (disk-detect/
Solution:
left as an exercise for the reader :)
I guess the udev 95-multipath.rules shouldn't be in the initramfs.
(i.e., add_udev_rules() in /usr/share/
multipath-
Booting on multipath devices would still be possible because there's
another call to 'multipath' on initramfs/
before mounting root.
Not sure about the behavior during system operation; e.g., hotplug
a new disk.. the multipath command would be called from the udev rule
in the root filesystem now (i.e., /lib/udev/rules.d/ from rootfs, not
initramfs). I'm now sure of how multipathd is related to that now.
Analysis:
Checking out why '/sbin/multipath -v0 /dev/sda' is timing out.
Boot with:
break=
<...>
Spawning shell within the initramfs
<...>
(initramfs)
Increase verbosity on multipath and udevd, and show udevd
And, to save time/output, reduce the udev timeout, and restrict that command
to only a single disk (e.g., sda).
udevd:
(initramfs) grep udevd /scripts/
/lib/
(initramfs) sed '/systemd-udevd/ { s:--daemon:--debug --event-timeout=5: ; s:$: 2>\&1 \&: }' -i /scripts/
(initramfs) grep udevd /scripts/
/lib/
multipath:
(initramfs) grep -F 'multipath -v' /lib/udev/
ACTION=
(initramfs) sed '/multipath -v/ { s:-v0:-v3: ; s:^:KERNEL=="sda", : }' -i /lib/udev/
(initramfs) grep -F 'multipath -v' /lib/udev/
KERNEL=="sda", ACTION=
Let initramfs continue:
(initramfs) exit
The udevd output rolls out.
The output of the multipath command is looping. Looking closer, it's always
restarting the multipath configuration process. At the end of each iteration
(it's looping..), there is this block:
'/sbin/multipath -v3 /dev/sda'(out) 'Mar 12 13:44:48 | mpath0: set ACT_CREATE (map does not exist)'
'/sbin/multipath -v3 /dev/sda'(out) 'Mar 12 13:44:48 | mpath0: failed to create map (in use)'
'/sbin/multipath -v3 /dev/sda'(out) 'Mar 12 13:44:48 | mpath0: domap (4294967295) failure for create/reload map'
'/sbin/multipath -v3 /dev/sda'(out) 'Mar 12 13:44:48 | restart multipath configuration process'
Searching multipath-tools source package for what causes that error message "failed to create map (in use)".
# apt-get source multipath-tools
# cd multipath-tools-*
# grep -r 'failed to create map (in use)' .
./libmultipat
And there it is, in domap() (also mentioned in the error):
extern int
domap (struct multipath * mpp)
{
...
case ACT_CREATE:
if (lock_multipath
return DOMAP_RETRY;
}
The error thus comes from lock_multipath(), in the same file:
static int
lock_multipath (struct multipath * mpp, int lock)
{
...
if (lock && flock(pp->fd, LOCK_EX | LOCK_NB) &&
So, basically, it's trying to lock a file w/ exclusive access flock(fd, LOCK_EX).
To check what file is that, on another system, which is booted already, let's use strace:
# strace -f strace.multipath multipath -v0 /dev/sda
<...>
26362 open("/dev/sda", O_RDONLY) = 5
<...>
26362 flock(5, LOCK_EX|LOCK_NB) = 0
<...>
OK; it tries to lock the same device that is passed as argument.
In order to discover the owner of the lock in the initramfs... hm..
there's no lsof or something.
Let's use a script to check every process's open files
(if a file is locked, it must be open; e.g., flock operates on an open file descriptor).
Reboot to that point again, in the initramfs (i.e., break=..., sed ...; NOT exit).
break=
(initramfs) sed '/systemd-udevd/ { s:--daemon:--debug --event-timeout=5: ; s:$: 2>\&1 \&: }' -i /scripts/
(initramfs) sed '/multipath -v/ { s:-v0:-v3: ; s:^:KERNEL=="sda", : }' -i /lib/udev/
But now *REPLACE* the multipath command to a script which searches for an
open fd for the device specified (expect sda, per the restriction inserted),
and list some details of the owning process.
note: we replace (not append) just to avoid the flock from multipath,
for not to confuse us.
(initramfs) sed 's:/sbin/multipath -v. /dev/:/find.sh :' -i /lib/udev/
(initramfs) grep -F 'find.sh' /lib/udev/
KERNEL=="sda", ACTION=
(initramfs) cat <<EOF >/find.sh
#!/bin/sh
#set -x
for dir in /proc/*
do
[ -d "\$dir/fd" ] || continue
ls -l \$dir/fd | grep -q \$1 || continue
echo "FD FOUND"
echo "process: \$dir"
ls -l \$dir/exe
echo "cmdline: \$(cat \$dir/cmdline | tr '\0' ' ')"
echo "file descriptors:"
ls -l \$dir/fd
done
EOF
OK; let's go for udev.
(initramfs) exit
Lots of udev output..
Searching back for the scripts' output (find.sh).. Tip: use 'screen'.
Got it.
The lock is from udevd.
See fd 6.
<...>
'/find.sh sda'(out) 'FD FOUND'
'/find.sh sda'(out) 'process: /proc/369'
'/find.sh sda'(out) 'lrwxrwxrwx 1 0 /proc/369/exe -> /lib/systemd/
'/find.sh sda'(out) 'cmdline: /lib/systemd/
'/find.sh sda'(out) 'file descriptors:'
'/find.sh sda'(out) 'lr-x------ 1 64 11 -> pipe:[8569]'
'/find.sh sda'(out) 'lrwx------ 1 64 10 -> socket:[8352]'
'/find.sh sda'(out) 'lrwx------ 1 64 9 -> anon_inode:
'/find.sh sda'(out) 'lrwx------ 1 64 8 -> socket:[8351]'
'/find.sh sda'(out) 'lr-x------ 1 64 7 -> pipe:[8568]'
'/find.sh sda'(out) 'lr-x------ 1 64 6 -> /dev/sda'
'/find.sh sda'(out) 'lr-x------ 1 64 5 -> anon_inode:inotify'
'/find.sh sda'(out) 'lrwx------ 1 64 4 -> anon_inode:
'/find.sh sda'(out) 'lrwx------ 1 64 3 -> anon_inode:
'/find.sh sda'(out) 'lrwx------ 1 64 2 -> /dev/console'
'/find.sh sda'(out) 'lrwx------ 1 64 1 -> /dev/console'
'/find.sh sda'(out) 'lr-x------ 1 64 0 -> /dev/null'
'/find.sh sda' [422] exit with return code 0
And if you search backwards for that PID, it reaches the fork of a udev worker:
seq 873 forked new worker [369]
Looking at udevd code for a worker:
# apt-get source systemd
# cd systemd-*
# grep -r worker .
hmm.. udevd.c.. ah, "worker_new".. looking.
static void worker_new(struct event *event) {
<...>
fd_lock = open(udev_
if (fd_lock >= 0 && flock(fd_lock, LOCK_SH|LOCK_NB) < 0) {
<...>
/* apply rules, create node, symlinks */
<...>
}
And there's a very meaningful comment above it:
/*
* Take a shared lock on the device node; this establishes
* a concept of device "ownership" to serialize device
* access. External processes holding an exclusive lock will
* cause udev to skip the event handling; in the case udev
* acquired the lock, the external process can block until
* udev has finished its event handling.
*/
Specially:
in the case udev
* acquired the lock, the external process can block until
* udev has finished its event handling.
AH.
So, that explains it all.
See:
1) udevd/worker acquires a lock of the block device (shared access),
2) process the udev rules (e.g., 95-multipath.rules)
3) *afterwards*, release the lock.
So, the 'multipath' command that is run inside the udev rule
that handles the add event of a block device (e.g., sda),
will never finish (will keep looping until killed by timeout),
because it requires an exclusive lock of that device..
however, that device already has a lock in place (locked by
udev worker before rule processing), which will only be
released after the rule processing (after multipath ends.)
tags: | added: architecture-ppc64le bugnameltc-122821 severity-critical targetmilestone-inin1504 |
Changed in multipath-tools (Ubuntu Trusty): | |
status: | New → In Progress |
Changed in multipath-tools (Ubuntu Vivid): | |
status: | New → In Progress |
Changed in multipath-tools (Ubuntu Trusty): | |
assignee: | nobody → Mathieu Trudel-Lapierre (mathieu-tl) |
Changed in multipath-tools (Ubuntu Vivid): | |
assignee: | nobody → Mathieu Trudel-Lapierre (mathieu-tl) |
Changed in multipath-tools (Ubuntu Trusty): | |
importance: | Undecided → High |
Changed in multipath-tools (Ubuntu Vivid): | |
importance: | Undecided → High |
description: | updated |
no longer affects: | multipath-tools (Ubuntu Vivid) |
The work-around in use:
Remove the multipath udev rules from the initramfs.
Note: this doesn't remove multipath support from it; there's more in there.
Boot from multipath devices works normally (and faster :-)
$ grep 'for rules in' /usr/share/ initramfs- tools/hooks/ multipath
for rules in 95-multipath.rules; do
$ sudo sed '/for rules in/ s:95-multipath. rules:: ' -i /usr/share/ initramfs- tools/hooks/ multipath
$ grep 'for rules in' /usr/share/ initramfs- tools/hooks/ multipath
for rules in ; do
$ sudo update-initramfs -u img-3.19. 0-7-generic
update-initramfs: Generating /boot/initrd.
$ sudo reboot