In the
previous logs, the multipath daemon wasn’t running. Attached is the new
log file, which has the path checker logs too. -Murthy From: Hi Alasdair, As per yesterday’s teleconf, I am
sending the snapshot of the /var/log/messages, which has the messages logged
when testing the basic failback functionality. The testing is conducted on
the host with RHEL U1 and single controller of HP Storageworks HSV110 array. As
each HSV110 controller has 2 ports, we effectively see 2 paths per lun. I am
using 0.4.5.44 version of multipath tools. Following is the observation during
testing the path failback. a) When the path is made unavailable
(/dev/sdd) for a logical device “mp1” on a multipath target,
the status of the path becomes [faulty][active] mp1 [size=1
GB][features="0"][hwhandler="0"] \_
round-robin 0 [active][best] \_
0:0:0:1 sda 8:0 [faulty][active] \_
round-robin 0 [enabled] \_
1:0:0:1 sdd 8:48 [ready][active] b) When an dd is executed on
/dev/mapper/mp1 (dd if=/dev/zero of=/dev/devmapper/mp1), the state of the paths
is as follows mp1 [size=1
GB][features="0"][hwhandler="0"] \_
round-robin 0 [enabled] \_
0:0:0:1 sda 8:0 [faulty][failed] \_
round-robin 0 [active][best] \_
1:0:0:1 sdd 8:48 [ready ][active] c) Now if the path (/dev/sda) is made
available for the same logical device, the status is as follows mp1 [size=1
GB][features="0"][hwhandler="0"] \_
round-robin 0 [enabled] \_
0:0:0:1 sda 8:0 [ready ][failed] \_
round-robin 0 [active][best] \_
1:0:0:1 sdd 8:48 [ready ][active] Note the path “/dev/sda” has
become [ready][failed] not [ready][active]. For this to change to
[ready][active], “multipath –v0” needs to be executed
manually. d) Now if path “/dev/sdd” is
made unavailable, then if “dd” is run on /dev/mapper/mp1, it
returns with input/output error, as none of the path will be in [ready][active]
state. The following is the state now: mp1 [size=1
GB][features="0"][hwhandler="0"] \_
round-robin 0 [enabled][best] \_
0:0:0:1 sda 8:0 [ready ][failed] \_
round-robin 0 [enabled] \_
1:0:0:1 sdd 8:48 [faulty][failed] If “multipath –v0”
executed from the command prompt the states get updated properly as mp1 [size=1
GB][features="0"][hwhandler="0"] \_
round-robin 0 [active][best] \_
0:0:0:1 sda 8:0 [ready ][active] \_
round-robin 0 [enabled] \_
1:0:0:1 sdd 8:48 [faulty][active] After this I will be able to do IO using
“dd”. How do we make the path state update properly
with out manually invoking “multipath –v0”? I am not sure on how to get the debug
build of multipath and multipathd binaries, if the information in the
messages.txt is insufficient, I need to test with the debug build and send the
new log. Any help in resolving this problem is
appreciated. Thanks and regards Murthy |
Jun 17 14:58:57 lxeagle multipathd: --------start up-------- Jun 17 14:58:57 lxeagle multipathd: read /etc/multipath.conf Jun 17 14:58:57 lxeagle kernel: SELinux: initialized (dev ramfs, type ramfs), uses genfs_contexts Jun 17 14:58:57 lxeagle multipathd: mp1: event checker started Jun 17 14:58:57 lxeagle multipathd: 3600508b4001019910000a00001720000: event checker started Jun 17 14:58:57 lxeagle multipathd: 3600508b4001019910000a00001780000: event checker started Jun 17 14:58:57 lxeagle multipathd: 3600508b4001019910000a000016c0000: event checker started Jun 17 14:58:57 lxeagle multipathd: path checkers start up Jun 17 14:58:57 lxeagle multipathd: 8:0: tur checker reports path is up Jun 17 14:58:57 lxeagle multipathd: 8:0: reinstated Jun 17 14:58:57 lxeagle multipathd: 8:16: tur checker reports path is up Jun 17 14:58:57 lxeagle multipathd: 8:16: reinstated Jun 17 14:58:57 lxeagle multipathd: 8:32: tur checker reports path is up Jun 17 14:58:57 lxeagle multipathd: 8:32: reinstated Jun 17 14:58:57 lxeagle multipathd: 8:48: tur checker reports path is up Jun 17 14:58:57 lxeagle multipathd: 8:48: reinstated Jun 17 14:58:57 lxeagle multipathd: 8:64: tur checker reports path is up Jun 17 14:58:57 lxeagle multipathd: 8:64: reinstated Jun 17 14:58:57 lxeagle multipathd: 8:80: tur checker reports path is up Jun 17 14:58:57 lxeagle multipathd: 8:80: reinstated Jun 17 14:59:03 lxeagle kernel: qla2300 0000:05:03.0: LOOP DOWN detected. <<=== PATH 1 MADE UNAVAILABLE Jun 17 15:00:03 lxeagle kernel: SCSI error : <0 0 0 1> return code = 0x10000 Jun 17 15:00:03 lxeagle kernel: end_request: I/O error, dev sda, sector 0 Jun 17 15:00:03 lxeagle kernel: device-mapper: dm-multipath: Failing path 8:0. Jun 17 15:00:03 lxeagle multipathd: 8:0: tur checker reports path is down Jun 17 15:00:03 lxeagle multipathd: checker failed path 8:0 in map 3600508b4001019910000a000016c0000 Jun 17 15:00:03 lxeagle multipathd: devmap event (41) on mp1 Jun 17 15:00:03 lxeagle multipathd: devmap event (42) on 3600508b4001019910000a000016c0000 Jun 17 15:00:03 lxeagle multipathd: 8:16: tur checker reports path is down Jun 17 15:00:03 lxeagle multipathd: checker failed path 8:16 in map 3600508b4001019910000a00001720000 Jun 17 15:00:03 lxeagle kernel: device-mapper: dm-multipath: Failing path 8:0. Jun 17 15:00:03 lxeagle kernel: device-mapper: dm-multipath: Failing path 8:16. Jun 17 15:00:03 lxeagle kernel: device-mapper: dm-multipath: Failing path 8:32. Jun 17 15:00:03 lxeagle multipathd: devmap event (50) on 3600508b4001019910000a00001720000 Jun 17 15:00:03 lxeagle multipathd: 8:32: tur checker reports path is down Jun 17 15:00:03 lxeagle multipathd: checker failed path 8:32 in map 3600508b4001019910000a00001780000 Jun 17 15:00:03 lxeagle multipathd: devmap event (50) on 3600508b4001019910000a00001780000 Jun 17 15:00:52 lxeagle kernel: qla2300 0000:05:03.0: LIP reset occured (f7f7). Jun 17 15:00:52 lxeagle kernel: qla2300 0000:05:03.0: LOOP UP detected (2 Gbps). <<=== PATH 1 MADE AVAILABLE Jun 17 15:01:01 lxeagle crond(pam_unix)[5418]: session opened for user root by (uid=0) Jun 17 15:01:01 lxeagle crond(pam_unix)[5418]: session closed for user root Jun 17 15:01:09 lxeagle multipathd: 8:0: tur checker reports path is up Jun 17 15:01:09 lxeagle multipathd: 8:0: reinstated Jun 17 15:01:09 lxeagle multipathd: 8:16: tur checker reports path is up Jun 17 15:01:09 lxeagle multipathd: devmap event (43) on 3600508b4001019910000a000016c0000 Jun 17 15:01:09 lxeagle multipathd: 8:16: reinstated Jun 17 15:01:09 lxeagle multipathd: devmap event (51) on 3600508b4001019910000a00001720000 Jun 17 15:01:09 lxeagle multipathd: 8:32: tur checker reports path is up Jun 17 15:01:09 lxeagle multipathd: 8:32: reinstated Jun 17 15:01:09 lxeagle multipathd: devmap event (51) on 3600508b4001019910000a00001780000 Jun 17 15:01:51 lxeagle kernel: qla2300 0000:05:04.0: LOOP DOWN detected. <<=== PATH 2 MADE UNAVAILABLE Jun 17 15:02:48 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x20000 Jun 17 15:02:48 lxeagle kernel: end_request: I/O error, dev sdd, sector 1246200 Jun 17 15:02:48 lxeagle kernel: device-mapper: dm-multipath: Failing path 8:48. Jun 17 15:02:48 lxeagle multipathd: devmap event (42) on mp1 Jun 17 15:02:48 lxeagle kernel: printk: 25505 messages suppressed. Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143684 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143685 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143686 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143687 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143688 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143689 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143690 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143691 Jun 17 15:02:48 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:48 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143692 Jun 17 15:02:49 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:49 lxeagle kernel: Buffer I/O error on device dm-0, logical block 143693 Jun 17 15:02:49 lxeagle kernel: lost page write due to I/O error on dm-0 Jun 17 15:02:50 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1045760 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1045768 Jun 17 15:02:50 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1046784 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1046792 Jun 17 15:02:50 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1047808 Jun 17 15:02:50 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1047816 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1047824 Jun 17 15:02:50 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1048840 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1048848 Jun 17 15:02:50 lxeagle multipathd: 8:48: tur checker reports path is down Jun 17 15:02:50 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:50 lxeagle multipathd: checker failed path 8:48 in map 3600508b4001019910000a000016c0000 Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1049864 Jun 17 15:02:50 lxeagle multipathd: devmap event (44) on 3600508b4001019910000a000016c0000 Jun 17 15:02:50 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:50 lxeagle multipathd: 8:64: tur checker reports path is down Jun 17 15:02:50 lxeagle kernel: end_request: I/O error, dev sdd, sector 1049872 Jun 17 15:02:50 lxeagle multipathd: checker failed path 8:64 in map 3600508b4001019910000a00001720000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1049880 Jun 17 15:02:51 lxeagle multipathd: devmap event (52) on 3600508b4001019910000a00001720000 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle multipathd: 8:80: tur checker reports path is down Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1050896 Jun 17 15:02:51 lxeagle multipathd: checker failed path 8:80 in map 3600508b4001019910000a00001780000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1050904 Jun 17 15:02:51 lxeagle multipathd: 8:0: mark as failed Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle multipathd: devmap event (52) on 3600508b4001019910000a00001780000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1051920 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1051928 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1051936 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1052952 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1052960 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1053976 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1053984 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1053992 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1055008 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1055016 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1056032 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1056040 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1056048 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1057064 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1057072 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1058088 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1058096 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1058104 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1059120 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1059128 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1059768 Jun 17 15:02:51 lxeagle kernel: end_request: I/O error, dev sdd, sector 1059776 Jun 17 15:02:51 lxeagle kernel: SCSI error : <1 0 0 1> return code = 0x10000 Jun 17 15:03:01 lxeagle multipathd: 8:0: tur checker reports path is up Jun 17 15:03:01 lxeagle multipathd: 8:0: reinstated Jun 17 15:03:22 lxeagle kernel: qla2300 0000:05:04.0: LIP reset occured (f7f7). Jun 17 15:03:22 lxeagle kernel: qla2300 0000:05:04.0: LOOP UP detected (2 Gbps). <<=== PATH 2 MADE AVAILABLE Jun 17 15:03:34 lxeagle multipathd: 8:48: tur checker reports path is up Jun 17 15:03:34 lxeagle multipathd: 8:48: reinstated Jun 17 15:03:34 lxeagle multipathd: 8:64: tur checker reports path is up Jun 17 15:03:34 lxeagle multipathd: devmap event (45) on 3600508b4001019910000a000016c0000 Jun 17 15:03:34 lxeagle multipathd: 8:64: reinstated Jun 17 15:03:34 lxeagle multipathd: devmap event (53) on 3600508b4001019910000a00001720000 Jun 17 15:03:34 lxeagle multipathd: 8:80: tur checker reports path is up Jun 17 15:03:34 lxeagle multipathd: 8:80: reinstated Jun 17 15:03:34 lxeagle multipathd: devmap event (53) on 3600508b4001019910000a00001780000