constantly changes /dev/disk/by-id/{scsi,wwn}-* LUN symlinks with multipathing

Bug #644489 reported by John Morrissey on 2010-09-21
28
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Ubuntu
Undecided
Unassigned
Lucid
Undecided
Unassigned
Maverick
Undecided
Unassigned
Natty
Undecided
Unassigned
multipath-tools (Ubuntu)
High
Peter Petrakis
Lucid
Undecided
Unassigned
Maverick
Undecided
Unassigned
Natty
Undecided
Unassigned

Bug Description

= SRU Justification =

== Impact ==
Multipath-tools is inadvertedly generating UDEV CHANGE events for the SD
block devices under it's control. These change events feedback into the udev
rules, increasing cpu utlilzation, and ruining the multipath aliasing feature,
which allows one to rename a multipath path from a series of letters and
numbers, to a human readable label. It gives users the impression that
the SAN is unstable.

== Solution ==
Change the open() flags in the priority checkers to read only from read write, this
stops sd from generating a change event after the file descriptor has been
closed.

Patch: https://bugs.launchpad.net/ubuntu/+source/multipath-tools/+bug/644489/+attachment/2177364/+files/multipath-tools-eliminate-udev-change-events-lp644489.debdiff

== Reproduction ==

Is easy, and doesn't even require a SAN. Since we're dealing with simple SCSI
inquiry cmds any block device will do. Simply install multipath-tools and
execute one of the priority checkers like so:

/sbin/mpath_prio_emc /dev/sda

also, have a window open monitoring udev, udevadm monitor, ensure
no change events to that block device are occurring before hand.

TEST CASE:
root@kickseed:~# udevadm monitor &
[1] 16950
root@kickseed:~# monitor will print the received events for:
UDEV - the event which udev sends out after rule processing
KERNEL - the kernel uevent
root@kickseed:~#
root@kickseed:~# /sbin/mpath_prio_emc /dev/sda
query command indicates error0
root@kickseed:~# KERNEL[1308688009.806317] change /devices/pci0000:00/0000:00:07.0/0000:04:00.0/host0/port-0:0/expander-0:0/port-0:0:1/end_device-0:0:1/target0:0:0/0:0:0:0/block/sda (block)
UDEV [1308688009.823569] change /devices/pci0000:00/0000:00:07.0/0000:04:00.0/host0/port-0:0/expander-0:0/port-0:0:1/end_device-0:0:1/target0:0:0/0:0:0:0/block/sda (block)

root@kickseed:~#
root@kickseed:~#
root@kickseed:~# /sbin/mpath_prio_alua /dev/sda
130

mpath_prio_alua doesn't generate any change events since it's open
flags do not include O_RDRW to begin with.

== regression potential ==
None, it's broken to begin with.
--------------------------

Binary package hint: udev

udevd constantly changes LUN device node symlinks (devices/LUNs, not the partition nodes) in /dev/disk/by-id. udevd uses ~15% of CPU and system time is using ~50-60%.

For example:

[<email address hidden>:pts/0 /dev/disk/by-id> ls -l wwn-0x60a98000486e5339576f596675735354 wwn-0x60a98000486e5339576f596675744c36 scsi-360a98000486e5339576f596675735354 scsi-360a98000486e5339576f596675744c36; sleep 1; echo '======'; ls -l wwn-0x60a98000486e5339576f596675735354 wwn-0x60a98000486e5339576f596675744c36 scsi-360a98000486e5339576f596675735354 scsi-360a98000486e5339576f596675744c36
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 scsi-360a98000486e5339576f596675735354 -> ../../sde
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 scsi-360a98000486e5339576f596675744c36 -> ../../sdf
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 wwn-0x60a98000486e5339576f596675735354 -> ../../sde
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 wwn-0x60a98000486e5339576f596675744c36 -> ../../sdf
======
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 scsi-360a98000486e5339576f596675735354 -> ../../sdg
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 scsi-360a98000486e5339576f596675744c36 -> ../../sdh
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 wwn-0x60a98000486e5339576f596675735354 -> ../../sdg
lrwxrwxrwx 1 root root 9 2010-09-21 16:12 wwn-0x60a98000486e5339576f596675744c36 -> ../../sdh

All other device nodes stay the same, such as the device nodes for the partitions:

[<email address hidden>:pts/0 /dev/disk/by-id> ls -l scsi-360a98000486e5339576f596675735354-part1; sleep 1; echo '======'; ls -l scsi-360a98000486e5339576f596675735354-part1
lrwxrwxrwx 1 root root 10 2010-09-21 15:47 scsi-360a98000486e5339576f596675735354-part1 -> ../../sdg1
======
lrwxrwxrwx 1 root root 10 2010-09-21 15:47 scsi-360a98000486e5339576f596675735354-part1 -> ../../sdg1

I'm not entirely sure whether this is udev's problem or something related to multipathing. Our most recent experience with multipathing is the last LTS release (hardy), which doesn't exhibit this behavior given similar configurations.

[<email address hidden>:pts/0 ~> sudo multipath -ll
rootvol (360a98000486e5339576f596675735354) dm-1 NETAPP ,LUN
[size=36G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=8][active]
 \_ 2:0:2:0 sda 8:0 [active][ready]
 \_ 3:0:2:0 sde 8:64 [active][ready]
\_ round-robin 0 [prio=2][enabled]
 \_ 3:0:3:0 sdg 8:96 [active][ready]
 \_ 2:0:3:0 sdc 8:32 [active][ready]
syslog-data (360a98000486e5339576f596675744c36) dm-0 NETAPP ,LUN
[size=1.0T][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=8][active]
 \_ 2:0:2:1 sdb 8:16 [active][ready]
 \_ 3:0:2:1 sdf 8:80 [active][ready]
\_ round-robin 0 [prio=2][enabled]
 \_ 3:0:3:1 sdh 8:112 [active][ready]
 \_ 2:0:3:1 sdd 8:48 [active][ready]
[<email address hidden>:pts/0 ~> cat /etc/multipath.conf
multipaths {
        multipath {
                wwid 360a98000486e5339576f596675735354
                alias rootvol
        }
        multipath {
                wwid 360a98000486e5339576f596675744c36
                alias syslog-data
        }
}

devices {
        device {
                vendor "NETAPP "
                product "LUN "
                path_checker tur
                path_grouping_policy group_by_prio
                prio_callout "/sbin/mpath_prio_netapp /dev/%n"
                failback immediate
                rr_min_io 128
                no_path_retry queue
        }
}

John Morrissey (jwm) wrote :
John Morrissey (jwm) wrote :

I should mention that this is with fully up-to-date lucid.

John Morrissey (jwm) wrote :

It looks like udev is responding to legitimate received events, based on 'udevadm monitor -e'. Commenting out the add|change action in 95-multipath.rules stops the spurious events and returns CPU consumption to expected levels.

John Morrissey (jwm) wrote :

For example, running 'multipath -v0 /dev/sda' while watching 'udevadm monitor -e' shows one event generated for each path, each time the multipath command is run. Each even would generate another multipath(8) invocation.

Looks like the multipath(8) action in 95-multipath.rules is causing an infinite event loop.

affects: udev (Ubuntu) → multipath-tools (Ubuntu)
John Morrissey (jwm) wrote :

Looks like this call to multipath(8) in the udev rules was added quite a while ago. I'm not sure where to go from here; our hardy machines don't exhibit this behavior, and I'm not sure what's generating the events or how to break the loop short of commenting out the udev rule action.

multipath-tools (0.4.8-11) unstable; urgency=low
[...]
  * [4f8a5d1] Call multipath via udev on block device add/change events This
    helps slow devices when either /etc/init.d/multipath-tools-boot or the
    initramfs script are being run although the devices are not ready yet.
    (Closes: #489850) - many thanks to Janusz Dziemidowicz for his suggestions
    and testing
[...]
 -- Guido Guenther <email address hidden> Wed, 30 Jul 2008 17:59:03 -0400

Thierry Carrez (ttx) on 2010-09-22
Changed in multipath-tools (Ubuntu):
importance: Undecided → High
status: New → Confirmed
Serge Hallyn (serge-hallyn) wrote :

Hi,

are you still having this problem? If so, I'd like to gather some debugging information.

John Morrissey (jwm) wrote :

What additional information do you need?

Serge Hallyn (serge-hallyn) wrote :

Please run multipathd with '-v4', and after a few events post /var/log/daemon.log. This should have some very useful info.

I'd also be curious to see what
 /sbin/mpath_prio_netapp /dev/<n>
gives you for a valid <n>.

John Morrissey (jwm) wrote :
Download full text (4.9 KiB)

Wasn't sure which /dev paths you were interested in specifically, so here's ~everything that might be relevant.

We don't run the stock syslog configuration, so I filtered out multipathd verbose output from our syslogs and attached it; let me know if you were looking for something more than multipathd's verbose syslogs.

[<email address hidden>:pts/0 ~> for i in /dev/disk/by-id/* /dev/sd*; do echo -n "$i "; sudo /sbin/mpath_prio_netapp "$i"; done
/dev/disk/by-id/dm-name-rootvol 4
/dev/disk/by-id/dm-name-rootvol-part1 4
/dev/disk/by-id/dm-name-rootvol-part10 4
/dev/disk/by-id/dm-name-rootvol-part11 4
/dev/disk/by-id/dm-name-rootvol-part12 4
/dev/disk/by-id/dm-name-rootvol-part13 4
/dev/disk/by-id/dm-name-rootvol-part14 4
/dev/disk/by-id/dm-name-rootvol-part15 4
/dev/disk/by-id/dm-name-rootvol-part2 4
/dev/disk/by-id/dm-name-rootvol-part5 4
/dev/disk/by-id/dm-name-rootvol-part6 4
/dev/disk/by-id/dm-name-rootvol-part7 4
/dev/disk/by-id/dm-name-rootvol-part8 4
/dev/disk/by-id/dm-name-rootvol-part9 4
/dev/disk/by-id/dm-uuid-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part1-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part10-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part11-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part12-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part13-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part14-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part15-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part2-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part5-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part6-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part7-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part8-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/dm-uuid-part9-mpath-360a98000486e5339576f5336524d5273 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273 1
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part1 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part10 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part11 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part12 1
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part13 1
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part14 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part15 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part2 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part5 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part6 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part7 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part8 4
/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273-part9 4
/dev/disk/by-id/scsi-rootvol 4
/dev/disk/by-id/scsi-rootvol-part1 4
/dev/disk/by-id/scsi-rootvol-part10 4
/dev/disk/by-id/scsi-rootvol-part11 4
/dev/disk/by-id/scsi-rootvol-part12 4
/dev/disk/by-id/scsi-rootvol-part13 4
/dev/disk/by-id/scsi-rootvol-part14 4
/dev/disk/by-id/scsi-rootvol-part15 4
/dev/d...

Read more...

John Morrissey (jwm) wrote :

I should also note that the errant behavior has changed a little since we first observed it; events used to be generated constantly, but now there are large bursts every ~20s.

Serge Hallyn (serge-hallyn) wrote :

Thanks, John. Looking at the info, udev is sending 'change' uevents for the LUNs every few seconds. So I don't know that multipath is doing anything wrong, the question is why are the uevents being sent?

Serge Hallyn (serge-hallyn) wrote :

Could you attach /var/log/udev, or whatever your udev logs might be?

John Morrissey (jwm) wrote :

Here are the udevd syslogs corresponding to the multipathd verbose logs in #9.

I also ran udevd with --debug; the debug output is attached and the corresponding syslogs are far below.

Apr 8 23:10:44 pxe-237 udevd-work[3952]: symlink(../../sda, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp) failed: File exists
Apr 8 23:12:39 pxe-237 udevd-work[16908]: symlink(../../sdb, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp) failed: File exists
Apr 8 23:15:44 pxe-237 udevd-work[6774]: rename(/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273) failed: No such file or directory
Apr 8 23:16:20 pxe-237 udevd-work[29981]: rename(/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273) failed: No such file or directory
Apr 8 23:16:56 pxe-237 udevd-work[11388]: symlink(../../sdd, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp) failed: File exists
Apr 8 23:16:58 pxe-237 udevd-work[8246]: rename(/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273) failed: No such file or directory
Apr 8 23:16:59 pxe-237 udevd-work[8246]: symlink(../../sdb, /dev/disk/by-id/wwn-0x60a98000486e5339576f5336524d5273.udev-tmp) failed: File exists
Apr 8 23:17:00 pxe-237 udevd-work[8246]: rename(/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273) failed: No such file or directory

Apr 12 23:37:59 pxe-237 udevd-work[6391]: rename(/dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273) failed: No such file or directory
Apr 12 23:37:59 pxe-237 udevd-work[6399]: symlink(../../sdc, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp) failed: File exists
Apr 12 23:37:59 pxe-237 udevd-work[6399]: symlink(../../sdc, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp) failed: File exists
Apr 12 23:37:59 pxe-237 udevd-work[6399]: symlink(../../sdc, /dev/disk/by-id/wwn-0x60a98000486e5339576f5336524d5273.udev-tmp) failed: File exists
Apr 12 23:37:59 pxe-237 udevd-work[6395]: symlink(../../sdb, /dev/disk/by-id/scsi-360a98000486e5339576f5336524d5273.udev-tmp) failed: File exists

Serge Hallyn (serge-hallyn) wrote :

Hi,

sorry, the bulb is slowly, dimly, turning on. You are the one who submitted bug 644481. Does fixing the rule to use '-q' fix this bug for you?

On Wed, Apr 13, 2011 at 03:59:58PM -0000, Serge Hallyn wrote:
> Does fixing the rule to use '-q' fix this bug for you?

Doesn't seem to. Changing the one instance of -Q in
/lib/udev/rules.d/95-kpartx.rules to -q doesn't change the behavior
described in this bug.

john
--
John Morrissey _o /\ ---- __o
<email address hidden> _-< \_ / \ ---- < \,
www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

Serge Hallyn (serge-hallyn) wrote :

Hi Peter,

I assigned this to you to get your feedback. To summarize this bug,
the line

# Coalesce multipath devices before multipathd is running (initramfs, early
# boot)
ACTION=="add|change", SUBSYSTEM=="block", RUN+="/sbin/multipath -v0 /dev/%k"

in 95-multipath.tools udev rule was added to:

multipath-tools (0.4.8-11) unstable; urgency=low
[...]
  * [4f8a5d1] Call multipath via udev on block device add/change events This
    helps slow devices when either /etc/init.d/multipath-tools-boot or the
    initramfs script are being run although the devices are not ready yet.
    (Closes: #489850) - many thanks to Janusz Dziemidowicz for his suggestions
    and testing
[...]

However, for some reason calling 'multipath -v0 /dev/sdb' for this user
causes udev to fire off a changed rule for /dev/sdb, triggering this
rule, causing multipath to be called, etc.

My first suggestion is that we keep this rule only for 'add' but not for
'change'. Having it for 'change' doesn't seem to meet the reasons why
it was originally aded.

Secondly, should we drop this rule altogether and just make sure to
load scsi_wait_scan and then do udevsettle? Or will that miss devices
which magically show up later (but not too late)?

(Please feel free to assign to me after commenting)

Changed in multipath-tools (Ubuntu):
assignee: nobody → Peter Petrakis (peter-petrakis)

We had another incident of this fault, but with an EMC Clariion CX4-120.
After eliminating LVM, and moving to a default MP config. It wasn't
until we removed the "change" rule to the 95-multipath.tools script
that the udev error messages ceased. I'm convinced that this
approach for the boot scripts is broken now and requires additional
scrutiny.

@John, I've got a test for you.

- stop multipathd: service multipath-tools stop
- monitor udev events as root: udevadm monitor

There should be no new change events.

then in a separate terminal, as root run:
/sbin/mpath_prio_netapp /dev/sdb (or any netapp device)

do you see a change event each time you run the cmd above?

Thanks.

John Morrissey (jwm) wrote :
Download full text (48.8 KiB)

On Fri, Jun 17, 2011 at 08:17:11PM -0000, Peter Petrakis wrote:
> - stop multipathd: service multipath-tools stop
> - monitor udev events as root: udevadm monitor
>
> There should be no new change events.

Yup.

> then in a separate terminal, as root run:
> /sbin/mpath_prio_netapp /dev/sdb (or any netapp device)
>
> do you see a change event each time you run the cmd above?

Yes, dozens of them.

[<email address hidden>:pts/1 ~> ps aux | grep [m]ulti
[<email address hidden>:pts/1 ~> sudo mpath_prio_netapp /dev/sdb
1
[<email address hidden>:pts/1 ~> echo $?
0

udevadm monitor emits:

KERNEL[1308405712.424857] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-3/target2:0:3/2:0:3:0/block/sdb (block)
KERNEL[1308405712.435407] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-2/target2:0:2/2:0:2:0/block/sda (block)
KERNEL[1308405712.440011] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-2/target3:0:2/3:0:2:0/block/sdc (block)
KERNEL[1308405712.440338] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-2/target3:0:2/3:0:2:0/block/sdc (block)
KERNEL[1308405712.443511] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-3/target3:0:3/3:0:3:0/block/sdd (block)
KERNEL[1308405712.443877] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-3/target3:0:3/3:0:3:0/block/sdd (block)
UDEV [1308405712.446513] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-3/target2:0:3/2:0:3:0/block/sdb (block)
KERNEL[1308405712.448729] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-3/target2:0:3/2:0:3:0/block/sdb (block)
UDEV [1308405712.458619] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-2/target2:0:2/2:0:2:0/block/sda (block)
KERNEL[1308405712.459048] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-2/target2:0:2/2:0:2:0/block/sda (block)
UDEV [1308405712.463894] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-2/target3:0:2/3:0:2:0/block/sdc (block)
UDEV [1308405712.465825] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-3/target3:0:3/3:0:3:0/block/sdd (block)
UDEV [1308405712.472381] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-3/target2:0:3/2:0:3:0/block/sdb (block)
KERNEL[1308405712.483274] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-3/target2:0:3/2:0:3:0/block/sdb (block)
UDEV [1308405712.488120] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.0/host2/rport-2:0-2/target2:0:2/2:0:2:0/block/sda (block)
UDEV [1308405712.491261] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-2/target3:0:2/3:0:2:0/block/sdc (block)
UDEV [1308405712.493597] change /devices/pci0000:00/0000:00:02.0/0000:07:00.3/0000:08:01.1/host3/rport-3:0-3/target3:0:3/3:0:3:0/block/sdd (block)
KERNEL[1308405712.494358] change /devices/pci0000:00/0000:00:02....

Excellent, you're still interested. I've got a fix for you to try.
Attached is a custom version of mpath_prio_netapp that should
not generate any more change events for you. Please post
for comparison that this new version returns the same data
as the old one.

move the old mpath_prio_netapp to /sbin/mpath_prio_netapp.old

cp the new one into sbin.

post the results of the following script
(adjust device range accordingly)

for i in sd[a-z]; do /sbin/mpath_prio_netapp.old $i; done

for i in sd[a-z]; do /sbin/mpath_prio_netapp $i; done

Verify that the same values are returned from each run,
and update the bug with your results.

Once you verify that the updated prio checker no longer
generates change events, start up multipathd again and
verify that this continues to be true. Thanks!

John Morrissey (jwm) wrote :

On Sat, Jun 18, 2011 at 09:00:59PM -0000, Peter Petrakis wrote:
> Excellent, you're still interested. I've got a fix for you to try.
> Attached is a custom version of mpath_prio_netapp

Would you provide a patch to multipath-tools instead, please? I'd be more
comfortable building a patched binary myself.

john
--
John Morrissey _o /\ ---- __o
<email address hidden> _-< \_ / \ ---- < \,
www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

I can understand that. Attached is a debdiff of the updated package.
I must stress that may not be the final form of the solution. I'm
chatting with Douglas Gilbert (sg io maintainer) now about this.
So far it appears that using an SD device as the target for sg io
can have unintended side effects, like the ones we've been observing.
If the corresponding SG device was used to begin with, this problem
would have never occurred.

See for yourself, mpath_prio_netapp /dev/sg0

In the meanwhile, this patch adjusts the open flag s.t. the "side effect"
no longer occurs. What's annoying is the upstream multipath (0.4.9) is
still using SD devices for this work but they did change all of their
open flags to O_RDONLY. Which leads me to believe they worked around
this side effect too, perhaps unaware of the fact that they were causing
these events to begin with by using sd devices by default.

You can simply build the mpath_prio_netapp straight from
path_priority/pp_netapp/ assuming build deps are met.

John Morrissey (jwm) wrote :

On Sat, Jun 18, 2011 at 09:00:59PM -0000, Peter Petrakis wrote:
> Excellent, you're still interested. I've got a fix for you to try.
> Attached is a custom version of mpath_prio_netapp that should
> not generate any more change events for you. Please post
> for comparison that this new version returns the same data
> as the old one.
[snip]
> Once you verify that the updated prio checker no longer
> generates change events, start up multipathd again and
> verify that this continues to be true. Thanks!

Everything seems to be as anticipated:

[<email address hidden>:pts/0 ~> sudo apt-get install multipath-tools=0.4.8-14ubuntu4 multipath-tools-boot=0.4.8-14ubuntu4 kpartx=0.4.8-14ubuntu4
[...]
[<email address hidden>:pts/0 ~> for i in /dev/sd[abcd]; do sudo mpath_prio_netapp $i; done
4
1
4
1
[<email address hidden>:pts/0 ~> sudo apt-get dist-upgrade
[...]
Preparing to replace kpartx 0.4.8-14ubuntu4 (using .../kpartx_0.4.8-14ubuntu5~lp644489_amd64.deb) ...
[...]
Preparing to replace multipath-tools 0.4.8-14ubuntu4 (using .../multipath-tools_0.4.8-14ubuntu5~lp644489_amd64.deb) ...
[...]
Preparing to replace multipath-tools-boot 0.4.8-14ubuntu4 (using .../multipath-tools-boot_0.4.8-14ubuntu5~lp644489_all.deb) ...
[...]
[<email address hidden>:pts/0 ~> for i in /dev/sd[abcd]; do sudo mpath_prio_netapp $i; done
4
1
4
1
[<email address hidden>:pts/0 ~> psg multi
root 30498 30498 0.0 0.0 85396 3500 ? SLl futex_ 13:24 /sbin/multipathd
root 30498 30500 0.0 0.0 85396 3500 ? SLl futex_ 13:24 /sbin/multipathd
root 30498 30514 0.0 0.0 85396 3500 ? SLl dm_wai 13:24 /sbin/multipathd
root 30498 30515 0.0 0.0 85396 3500 ? SLl hrtime 13:24 /sbin/multipathd
root 30498 30516 0.0 0.0 85396 3500 ? SLl skb_re 13:24 /sbin/multipathd
root 30498 30517 0.0 0.0 85396 3500 ? SLl poll_s 13:24 /sbin/multipathd
root 30498 30518 0.0 0.0 85396 3500 ? SLl futex_ 13:24 /sbin/multipathd
[<email address hidden>:pts/0 ~> sudo udevadm monitor
monitor will print the received events for:
UDEV - the event which udev sends out after rule processing
KERNEL - the kernel uevent

[no events generated]

john
--
John Morrissey _o /\ ---- __o
<email address hidden> _-< \_ / \ ---- < \,
www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

Changed in multipath-tools (Ubuntu):
status: Confirmed → In Progress
Changed in udev (Ubuntu):
status: New → Invalid

After chatting with Douglas Gilbert on this I know have a better
understanding of the problem. This very issue has been raised by
him before on linux-scsi and it never saw final resolution.

http://kerneltrap.org/mailarchive/linux-scsi/2010/2/15/6778453

When the file descriptor to the SD device is closed, the change
event occurs, presumably because it was opened with O_RDRW
to begin with, though nothing actually changed.

By changing that flag to O_RDONLY, no udev events are generated
when the fd closes. It doesn't address the root cause but it's
sufficient to get us unjammed safely while we continue to work
on a better solution. That solution may be adjusting the multipath
priority checkers to use the corresponding sg devices when
presented with an sd device. Either way, there's more work to do.

Since all the priority checkers amount to different degrees of
scsi inquiry, and vendor specific san interrogation commands. I
believe we're safe with the O_RDONLY approach. All data
direction flags for sg io in this case are SG_DXFER_FROM_DEV
or SG_DXFER_NONE.

Changed in multipath-tools (Ubuntu):
status: In Progress → Fix Released
Changed in multipath-tools (Ubuntu Lucid):
status: New → Confirmed
Changed in multipath-tools (Ubuntu Maverick):
status: New → Confirmed
Changed in multipath-tools (Ubuntu Natty):
status: New → Confirmed

also affects udev should be removed.

Changed in udev (Ubuntu Lucid):
status: New → Invalid
Changed in udev (Ubuntu Maverick):
status: New → Invalid
Changed in udev (Ubuntu Natty):
status: New → Invalid
affects: udev (Ubuntu) → ubuntu
description: updated
Serge Hallyn (serge-hallyn) wrote :

To make sure this is clear, the issue appears to be fixed (per the testcase and source code) in the 0.4.9 version merged into oneiric. The debdiff above is needed for lucid-natty.

Changed in ubuntu:
status: Invalid → Confirmed

Accepted multipath-tools into natty-proposed, the package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

Changed in ubuntu:
status: Confirmed → Invalid
Changed in multipath-tools (Ubuntu Natty):
status: Confirmed → Fix Committed
tags: added: verification-needed

On Fri, Jun 24, 2011 at 04:04:46PM -0000, Martin Pitt wrote:
> Accepted multipath-tools into natty-proposed, the package will build now
> and be available in a few hours.
[snip]
> ** Changed in: ubuntu
> Status: Confirmed => Invalid
>
> ** Changed in: Ubuntu Lucid
> Status: Confirmed => Invalid

So this won't be SRU'd for lucid? Unfortunately, I don't have any affected
machines running natty, and can't upgrade the affected lucid machine(s) to
that release in order to provide feedback.

john
--
John Morrissey _o /\ ---- __o
<email address hidden> _-< \_ / \ ---- < \,
www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

Serge Hallyn (serge-hallyn) wrote :

@John,

the bug was also nominated for lucid. The proposed package just hasn't been accepted (yet) into lucid-proposed, but I've seen no indication that it was rejected.

John Morrissey (jwm) wrote :

On Fri, Jun 24, 2011 at 05:15:33PM -0000, Serge Hallyn wrote:
> the bug was also nominated for lucid. The proposed package just hasn't
> been accepted (yet) into lucid-proposed, but I've seen no indication
> that it was rejected.

Cool. Does the LP bug get notified when it's accepted into -proposed, or
should I check for it in -proposed periodically?

john
--
John Morrissey _o /\ ---- __o
<email address hidden> _-< \_ / \ ---- < \,
www.horde.net/ __(_)/_(_)________/ \_______(_) /_(_)__

Serge Hallyn (serge-hallyn) wrote :

Quoting John Morrissey (<email address hidden>):
> On Fri, Jun 24, 2011 at 05:15:33PM -0000, Serge Hallyn wrote:
> > the bug was also nominated for lucid. The proposed package just hasn't
> > been accepted (yet) into lucid-proposed, but I've seen no indication
> > that it was rejected.
>
> Cool. Does the LP bug get notified when it's accepted into -proposed, or
> should I check for it in -proposed periodically?

I think it'll get notified.

@ Martin

fix verified, no udev change events generated.

root@kickseed:~# udevadm monitor
monitor will print the received events for:
UDEV - the event which udev sends out after rule processing
KERNEL - the kernel uevent
^Z
[1]+ Stopped udevadm monitor
root@kickseed:~# bg
[1]+ udevadm monitor &
root@kickseed:~# apt-cache policy multipath-tools
multipath-tools:
  Installed: 0.4.8-14ubuntu10.1
  Candidate: 0.4.8-14ubuntu10.1
  Version table:
 *** 0.4.8-14ubuntu10.1 0
        500 http://us.archive.ubuntu.com/ubuntu/ natty-proposed/main Packages
        100 /var/lib/dpkg/status
     0.4.8-14ubuntu10 0
        500 http://10.229.0.1/enablement/lucid-mpio-ubuntu/ lucid/main Packages
     0.4.8-14ubuntu4 0
        500 http://us.archive.ubuntu.com/ubuntu/ lucid/main Packages
root@kickseed:~#
root@kickseed:~# /sbin/mpath_prio_netapp /dev/sda
SCSI error
- SCSI CDB: 0xc0 0x00 0x01 0x0a 0x98 0x0a 0x41 0x80 0x00 0x00
- masked_status=0x01, host_status=0x00, driver_status=0x08
- SCSI sense data: 0x70 0x00 0x05 0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 0x00 0x20 0x00 0x00 0x00 0x00 0x00 0x00 0x00
SCSI error
- SCSI CDB: 0x12 0x01 0xc1 0x00 0x80 0x00
- masked_status=0x01, host_status=0x00, driver_status=0x08
- SCSI sense data: 0x70 0x00 0x05 0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 0x00 0x24 0x00 0x00 0x00 0x00 0x00 0x00 0x00
4
root@kickseed:~#
root@kickseed:~#
root@kickseed:~# /sbin/mpath_prio_netapp /dev/sdb
SCSI error
- SCSI CDB: 0xc0 0x00 0x01 0x0a 0x98 0x0a 0x41 0x80 0x00 0x00
- masked_status=0x01, host_status=0x00, driver_status=0x08
- SCSI sense data: 0x70 0x00 0x05 0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 0x00 0x20 0x00 0x00 0x00 0x00 0x00 0x00 0x00
SCSI error
- SCSI CDB: 0x12 0x01 0xc1 0x00 0x80 0x00
- masked_status=0x01, host_status=0x00, driver_status=0x08
- SCSI sense data: 0x70 0x00 0x05 0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 0x00 0x24 0x00 0x00 0x00 0x00 0x00 0x00 0x00
4
root@kickseed:~# /sbin/mpath_prio_emc /dev/sdb
query command indicates error0
root@kickseed:~#
root@kickseed:~#
root@kickseed:~# /sbin/mpath_prio_emc /dev/sda
query command indicates error0
root@kickseed:~#
root@kickseed:~#
root@kickseed:~# jobs
[1]+ Running udevadm monitor &

Martin Pitt (pitti) wrote :

John Morrissey [2011-06-24 16:51 -0000]:
> So this won't be SRU'd for lucid?

It will. I just closed the useless generic "Ubuntu" tasks. A proper
package task is enough.

Martin
--
Martin Pitt | http://www.piware.de
Ubuntu Developer (www.ubuntu.com) | Debian Developer (www.debian.org)

tags: added: verification-done verification-done-natty
removed: verification-needed

Accepted multipath-tools into maverick-proposed, the package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

Changed in multipath-tools (Ubuntu Maverick):
status: Confirmed → Fix Committed
tags: removed: verification-done
tags: added: verification-needed
Clint Byrum (clint-fewbar) wrote :

Accepted multipath-tools into lucid-proposed, the package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

Changed in multipath-tools (Ubuntu Lucid):
status: Confirmed → Fix Committed

@Clint

Maverick verification: no udev change events observed

root@kickseed:~# udevadm monitor &
[1] 1999
root@kickseed:~# monitor will print the received events for:
UDEV - the event which udev sends out after rule processing
KERNEL - the kernel uevent

root@kickseed:~# for i in /sbin/mpath_prio_*
> do
> echo "testing pathchecker $i"
> $i /dev/sda 2>/dev/null
> done
testing pathchecker /sbin/mpath_prio_alua
50
testing pathchecker /sbin/mpath_prio_balance_units
1
testing pathchecker /sbin/mpath_prio_emc
0
testing pathchecker /sbin/mpath_prio_hds_modular
0
testing pathchecker /sbin/mpath_prio_hp_sw
4
testing pathchecker /sbin/mpath_prio_netapp
4
testing pathchecker /sbin/mpath_prio_random
7
testing pathchecker /sbin/mpath_prio_rdac
0

root@kickseed:~# uname -a
Linux kickseed 2.6.35-30-generic #54-Ubuntu SMP Tue Jun 7 18:41:54 UTC 2011 x86_64 GNU/Linux

root@kickseed:~# apt-cache policy multipath-tools
multipath-tools:
  Installed: 0.4.8-14ubuntu4.10.10.1
  Candidate: 0.4.8-14ubuntu4.10.10.1
  Version table:
 *** 0.4.8-14ubuntu4.10.10.1 0
        500 http://us.archive.ubuntu.com/ubuntu/ maverick-proposed/main amd64 Packages
        100 /var/lib/dpkg/status
     0.4.8-14ubuntu4 0
        500 http://us.archive.ubuntu.com/ubuntu/ maverick/main amd64 Packages

root@kickseed:~# mount
/dev/mapper/2226500015588d809-part1 on / type ext4 (rw,errors=remount-ro)
...

@Clint

lucid verification: no udev change events observed
NOTE: this issue depends on lp #686832

root@kickseed:~# lsb_release -r
Release: 10.04

root@kickseed:~# udevadm monitor &
[1] 2043
monitor will print the received events for:
UDEV - the event which udev sends out after rule processing
KERNEL - the kernel uevent

root@kickseed:~# for i in /sbin/mpath_prio_*
> do
> echo "testing pathchecker $i"
> $i /dev/sda 2>/dev/null
> done
testing pathchecker /sbin/mpath_prio_alua
50
testing pathchecker /sbin/mpath_prio_balance_units
1
testing pathchecker /sbin/mpath_prio_emc
0
testing pathchecker /sbin/mpath_prio_hds_modular
0
testing pathchecker /sbin/mpath_prio_hp_sw
4
testing pathchecker /sbin/mpath_prio_netapp
4
testing pathchecker /sbin/mpath_prio_random
1
testing pathchecker /sbin/mpath_prio_rdac
0
root@kickseed:~# uname -a
Linux kickseed 2.6.32-32-generic #62-Ubuntu SMP Wed Apr 20 21:52:38 UTC 2011 x86_64 GNU/Linux

root@kickseed:~# apt-cache policy multipath-tools
multipath-tools:
  Installed: 0.4.8-14ubuntu4.10.04.1
  Candidate: 0.4.8-14ubuntu4.10.04.1
  Version table:
 *** 0.4.8-14ubuntu4.10.04.1 0
        500 http://us.archive.ubuntu.com/ubuntu/ lucid-proposed/main Packages
        100 /var/lib/dpkg/status
     0.4.8-14ubuntu4 0
        500 http://us.archive.ubuntu.com/ubuntu/ lucid/main Packages

root@kickseed:~# mount
/dev/mapper/2225000015568f586-part1 on / type ext4 (rw,errors=remount-ro)
...

Quoting Peter Petrakis (<email address hidden>):
> @Clint
>
> lucid verification: no udev change events observed
> NOTE: this issue depends on lp #686832

Not strictly though, right? Your setup needed that fix to boot,
but that is unrelated to this bugfix iiuc?

-serge

On 06/28/2011 09:30 PM, Serge Hallyn wrote:
> Quoting Peter Petrakis (<email address hidden>):
>> @Clint
>>
>> lucid verification: no udev change events observed
>> NOTE: this issue depends on lp #686832
>
> Not strictly though, right? Your setup needed that fix to boot,
> but that is unrelated to this bugfix iiuc?

That's exactly correct. Just ensuring the dependency, that before
multipath-tools lands in lucid-updates, lp #686832 must
be integrated. I don't want some random user taking this
deb and expecting their system will improve as a whole; they'll
be disappointed when they are unable to boot. Other than that,
consider this fix verified.

Peter

>
> -serge
>

Martin Pitt (pitti) on 2011-06-29
tags: added: verification-done
removed: verification-done-natty verification-needed
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package multipath-tools - 0.4.8-14ubuntu4.10.04.1

---------------
multipath-tools (0.4.8-14ubuntu4.10.04.1) lucid-proposed; urgency=high

  * Eliminate UDEV CHANGE events generated by mpath priority checkers. Due to
    quirk in how SG IO is handled by SD devices (LP: #644489).
 -- <email address hidden> (Peter M. Petrakis) Tue, 21 Jun 2011 14:13:12 -0400

Changed in multipath-tools (Ubuntu Lucid):
status: Fix Committed → Fix Released
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package multipath-tools - 0.4.8-14ubuntu4.10.10.1

---------------
multipath-tools (0.4.8-14ubuntu4.10.10.1) maverick-proposed; urgency=high

  * Eliminate UDEV CHANGE events generated by mpath priority checkers. Due to
    quirk in how SG IO is handled by SD devices (LP: #644489).
 -- <email address hidden> (Peter M. Petrakis) Tue, 21 Jun 2011 14:13:12 -0400

Changed in multipath-tools (Ubuntu Maverick):
status: Fix Committed → Fix Released
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package multipath-tools - 0.4.8-14ubuntu10.1

---------------
multipath-tools (0.4.8-14ubuntu10.1) natty-proposed; urgency=low

  * Eliminate UDEV CHANGE events generated by mpath priority checkers. Due to
    quirk in how SG IO is handled by SD devices (LP: #644489).
 -- <email address hidden> (Peter M. Petrakis) Tue, 21 Jun 2011 14:13:12 -0400

Changed in multipath-tools (Ubuntu Natty):
status: Fix Committed → Fix Released
tags: added: testcase
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers