The confusing output of the multipath -ll !

Latest response

We have all the following disks with write-protected, and we found some strange phenomena with the multipath -ll !

1) Why sometimes the output takes abnormally longer time, versus sometimes takes normally shorter time?
2) Why almost the failed disks are different everytime we run the multipath -ll in the same system scene ?

# 
# 
# 
# time multipath -ll
sda: checker msg is "tur checker reports path is down"
mpath127 (360060e800590e700000090e7000003fe) dm-9 HITACHI,OPEN-V
[size=50G][features=0][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:0:10 sda 8:0   [failed][faulty]
mpath49 (360060e800590e700000090e700000306) dm-17 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:7  sdi 8:128 [active][ready] 
mpath51 (360060e800590e700000090e700000308) dm-19 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:9  sdk 8:160 [active][ready] 
mpath48 (360060e800590e700000090e700000305) dm-13 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:6  sdh 8:112 [active][ready] 
mpath50 (360060e800590e700000090e700000307) dm-18 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:8  sdj 8:144 [active][ready] 
mpath47 (360060e800590e700000090e700000304) dm-16 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:5  sdg 8:96  [active][ready] 
mpath46 (360060e800590e700000090e700000303) dm-10 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:4  sdf 8:80  [active][ready] 
mpath45 (360060e800590e700000090e700000302) dm-15 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:3  sde 8:64  [active][ready] 
mpath44 (360060e800590e700000090e700000301) dm-12 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:2  sdd 8:48  [active][ready] 
mpath43 (360060e800590e700000090e700000300) dm-14 HITACHI,OPEN-V
[size=600G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:1  sdc 8:32  [active][ready] 
mpath42 (360060e800590e700000090e70000030a) dm-11 HITACHI,OPEN-V
[size=1.0G][features=1 queue_if_no_path][hwhandler=0]
\_ round-robin 0 [prio=0][active]
 \_ 14:0:1:0  sdb 8:16  [active][ready] 

real    0m0.017s
user    0m0.002s
sys     0m0.010s
# 
# 
# 
# 
# time multipath -ll|grep -i fail
 \_ 14:0:0:10 sda 8:0   [failed][faulty]
 \_ 14:0:1:7  sdi 8:128 [failed][ready] 
 \_ 14:0:1:8  sdj 8:144 [failed][ready] 
 \_ 14:0:1:5  sdg 8:96  [failed][ready] 
 \_ 14:0:1:2  sdd 8:48  [failed][faulty]
 \_ 14:0:1:1  sdc 8:32  [failed][ready] 

real    8m0.408s
user    0m0.003s
sys     0m0.008s
# 
# 
# 
# uptime
 11:25:14 up 683 days, 20:55,  2 users,  load average: 3.17, 3.27, 3.26
# 
# 
# 
# time multipath -ll|grep -i fail
 \_ 14:0:0:10 sda 8:0   [failed][faulty]
 \_ 14:0:1:9  sdk 8:160 [failed][ready] 
 \_ 14:0:1:3  sde 8:64  [failed][faulty]
 \_ 14:0:1:2  sdd 8:48  [failed][faulty]
 \_ 14:0:1:0  sdb 8:16  [failed][faulty]

real    2m58.287s
user    0m0.003s
sys     0m0.011s
# 
# 
# 
# uptime
 11:28:25 up 683 days, 20:59,  2 users,  load average: 4.09, 3.63, 3.40
# 
# 
# 
# 
# time multipath -ll|grep -i fail
 \_ 14:0:0:10 sda 8:0   [failed][faulty]
 \_ 14:0:1:2  sdd 8:48  [failed][ready] 

real    0m0.017s
user    0m0.004s
sys     0m0.014s
# 
# 
# 
# time multipath -ll|grep -i fail
 \_ 14:0:0:10 sda 8:0   [failed][faulty]
 \_ 14:0:1:2  sdd 8:48  [failed][ready] 

real    0m0.017s
user    0m0.004s
sys     0m0.011s
# 
# 
# 

The corresponding messages for multipath :

Feb 20 10:54:48 sccmsdoc2 kernel: device-mapper: multipath: Failing path 8:128.
Feb 20 10:54:48 sccmsdoc2 multipathd: mpath49: Entering recovery mode: max_retries=12 
Feb 20 10:54:48 sccmsdoc2 multipathd: mpath49: remaining active paths: 0 
Feb 20 10:59:48 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:88): Abort command issued -- 1 71e9c 2002.
Feb 20 10:59:48 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:8): Abort command issued -- 1 71e91 2002.
Feb 20 10:59:48 sccmsdoc2 multipathd: sdj: tur checker reports path is down 
Feb 20 10:59:48 sccmsdoc2 multipathd: checker failed path 8:144 in map mpath50 
Feb 20 10:59:48 sccmsdoc2 kernel: device-mapper: multipath: Failing path 8:144.
Feb 20 10:59:48 sccmsdoc2 multipathd: mpath50: Entering recovery mode: max_retries=12 
Feb 20 10:59:48 sccmsdoc2 multipathd: mpath50: remaining active paths: 0 
Feb 20 10:59:48 sccmsdoc2 multipathd: dm-14: add map (uevent) 
Feb 20 10:59:48 sccmsdoc2 multipathd: dm-14: devmap already registered 
Feb 20 10:59:48 sccmsdoc2 multipathd: mpath43: Entering recovery mode: max_retries=12 
Feb 20 10:59:48 sccmsdoc2 multipathd: mpath47: Entering recovery mode: max_retries=12 
Feb 20 10:59:48 sccmsdoc2 multipathd: mpath49: Entering recovery mode: max_retries=12 
Feb 20 10:59:48 sccmsdoc2 multipathd: mpath50: Entering recovery mode: max_retries=12 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-16: add map (uevent) 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-16: devmap already registered 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-17: add map (uevent) 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-17: devmap already registered 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-18: add map (uevent) 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-18: devmap already registered 
Feb 20 10:59:49 sccmsdoc2 multipathd: sdd: tur checker reports path is up 
Feb 20 10:59:49 sccmsdoc2 multipathd: 8:48: reinstated 
Feb 20 10:59:49 sccmsdoc2 multipathd: mpath44: queue_if_no_path enabled 
Feb 20 10:59:49 sccmsdoc2 multipathd: mpath44: Recovered to normal mode 
Feb 20 10:59:49 sccmsdoc2 multipathd: mpath44: remaining active paths: 1 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 10:59:49 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 10:59:49 sccmsdoc2 kernel: sd 14:0:1:2: SCSI error: return code = 0x00020000
Feb 20 10:59:49 sccmsdoc2 kernel: end_request: I/O error, dev sdd, sector 8
Feb 20 10:59:49 sccmsdoc2 kernel: device-mapper: multipath: Failing path 8:48.
Feb 20 10:59:50 sccmsdoc2 multipathd: 8:48: mark as failed 
Feb 20 10:59:50 sccmsdoc2 multipathd: mpath44: Entering recovery mode: max_retries=12 
Feb 20 10:59:50 sccmsdoc2 multipathd: mpath44: remaining active paths: 0 
Feb 20 11:04:48 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:89): Abort command issued -- 1 71ea4 2002.
Feb 20 11:04:48 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:2): Abort command issued -- 1 71ea3 2002.
Feb 20 11:04:48 sccmsdoc2 multipathd: sda: tur checker reports path is down 
Feb 20 11:04:52 sccmsdoc2 multipathd: sdc: tur checker reports path is up 
Feb 20 11:04:52 sccmsdoc2 multipathd: 8:32: reinstated 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath43: queue_if_no_path enabled 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath43: Recovered to normal mode 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath43: remaining active paths: 1 
Feb 20 11:04:52 sccmsdoc2 multipathd: sdg: tur checker reports path is up 
Feb 20 11:04:52 sccmsdoc2 multipathd: 8:96: reinstated 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath47: queue_if_no_path enabled 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath47: Recovered to normal mode 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath47: remaining active paths: 1 
Feb 20 11:04:52 sccmsdoc2 multipathd: sdi: tur checker reports path is up 
Feb 20 11:04:52 sccmsdoc2 multipathd: 8:128: reinstated 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath49: queue_if_no_path enabled 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath49: Recovered to normal mode 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath49: remaining active paths: 1 
Feb 20 11:04:52 sccmsdoc2 multipathd: sdj: tur checker reports path is up 
Feb 20 11:04:52 sccmsdoc2 multipathd: 8:144: reinstated 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath50: queue_if_no_path enabled 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath50: Recovered to normal mode 
Feb 20 11:04:52 sccmsdoc2 multipathd: mpath50: remaining active paths: 1 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-14: add map (uevent) 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-14: devmap already registered 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-16: add map (uevent) 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-16: devmap already registered 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-17: add map (uevent) 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-17: devmap already registered 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-18: add map (uevent) 
Feb 20 11:04:52 sccmsdoc2 multipathd: dm-18: devmap already registered 
Feb 20 11:04:53 sccmsdoc2 multipathd: sdd: tur checker reports path is up 
Feb 20 11:04:53 sccmsdoc2 multipathd: 8:48: reinstated 
Feb 20 11:04:53 sccmsdoc2 multipathd: mpath44: queue_if_no_path enabled 
Feb 20 11:04:53 sccmsdoc2 multipathd: mpath44: Recovered to normal mode 
Feb 20 11:04:53 sccmsdoc2 multipathd: mpath44: remaining active paths: 1 
Feb 20 11:04:53 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:04:53 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:04:53 sccmsdoc2 kernel: sd 14:0:1:2: SCSI error: return code = 0x00020000
Feb 20 11:04:53 sccmsdoc2 kernel: end_request: I/O error, dev sdd, sector 8
Feb 20 11:04:53 sccmsdoc2 kernel: device-mapper: multipath: Failing path 8:48.
Feb 20 11:04:53 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:04:54 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:121): Abort command issued -- 1 71eee 2002.
Feb 20 11:04:54 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:04:54 sccmsdoc2 multipathd: 8:48: mark as failed 
Feb 20 11:04:54 sccmsdoc2 multipathd: mpath44: Entering recovery mode: max_retries=12 
Feb 20 11:04:54 sccmsdoc2 multipathd: mpath44: remaining active paths: 0 
Feb 20 11:04:58 sccmsdoc2 multipathd: sda: tur checker reports path is down 
Feb 20 11:05:01 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:181): Abort command issued -- 1 71f76 2002.
Feb 20 11:05:03 sccmsdoc2 multipathd: sdd: tur checker reports path is up 



Feb 20 11:22:31 sccmsdoc2 multipathd: sdd: tur checker reports path is down 
Feb 20 11:22:46 sccmsdoc2 kernel:  rport-14:0-3: blocked FC remote port time out: saving binding
Feb 20 11:22:46 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:261): DEVICE RESET ISSUED.
Feb 20 11:22:46 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: qla2xxx_eh_device_reset: device reset failed
Feb 20 11:22:46 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:261): LOOP RESET ISSUED.
Feb 20 11:23:07 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: qla2xxx_eh_bus_reset: reset succeded
Feb 20 11:28:17 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:261): Abort command issued -- 1 7204f 2002.
Feb 20 11:28:17 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:9): Abort command issued -- 1 7204c 2002.
Feb 20 11:28:17 sccmsdoc2 multipathd: sdk: tur checker reports path is down 
Feb 20 11:28:22 sccmsdoc2 multipathd: sda: tur checker reports path is down 
Feb 20 11:28:23 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:331): Abort command issued -- 1 720e9 2002.
Feb 20 11:28:26 sccmsdoc2 multipathd: sde: tur checker reports path is up 
Feb 20 11:28:26 sccmsdoc2 multipathd: 8:64: reinstated 
Feb 20 11:28:26 sccmsdoc2 multipathd: mpath45: queue_if_no_path enabled 
Feb 20 11:28:26 sccmsdoc2 multipathd: mpath45: Recovered to normal mode 
Feb 20 11:28:26 sccmsdoc2 multipathd: mpath45: remaining active paths: 1 
Feb 20 11:28:26 sccmsdoc2 multipathd: dm-15: add map (uevent) 
Feb 20 11:28:26 sccmsdoc2 multipathd: dm-15: devmap already registered 
Feb 20 11:28:27 sccmsdoc2 multipathd: sdb: tur checker reports path is up 
Feb 20 11:28:27 sccmsdoc2 multipathd: 8:16: reinstated 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath42: queue_if_no_path enabled 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath42: Recovered to normal mode 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath42: remaining active paths: 1 
Feb 20 11:28:27 sccmsdoc2 multipathd: sdd: tur checker reports path is up 
Feb 20 11:28:27 sccmsdoc2 multipathd: 8:48: reinstated 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath44: queue_if_no_path enabled 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath44: Recovered to normal mode 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath44: remaining active paths: 1 
Feb 20 11:28:27 sccmsdoc2 multipathd: sdk: tur checker reports path is up 
Feb 20 11:28:27 sccmsdoc2 multipathd: 8:160: reinstated 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath51: queue_if_no_path enabled 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath51: Recovered to normal mode 
Feb 20 11:28:27 sccmsdoc2 multipathd: mpath51: remaining active paths: 1 
Feb 20 11:28:27 sccmsdoc2 multipathd: dm-11: add map (uevent) 
Feb 20 11:28:27 sccmsdoc2 multipathd: dm-11: devmap already registered 
Feb 20 11:28:27 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:28:27 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:28:27 sccmsdoc2 multipathd: dm-19: add map (uevent) 
Feb 20 11:28:27 sccmsdoc2 multipathd: dm-19: devmap already registered 
Feb 20 11:28:28 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:28:28 sccmsdoc2 kernel: sd 14:0:1:2: SCSI error: return code = 0x00020000
Feb 20 11:28:28 sccmsdoc2 kernel: end_request: I/O error, dev sdd, sector 184
Feb 20 11:28:28 sccmsdoc2 kernel: device-mapper: multipath: Failing path 8:48.
Feb 20 11:28:28 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:28:28 sccmsdoc2 multipathd: 8:48: mark as failed 
Feb 20 11:28:28 sccmsdoc2 multipathd: mpath44: Entering recovery mode: max_retries=12 
Feb 20 11:28:28 sccmsdoc2 multipathd: mpath44: remaining active paths: 0 
Feb 20 11:28:29 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:340): Abort command issued -- 1 720fc 2002.
Feb 20 11:28:32 sccmsdoc2 multipathd: sda: tur checker reports path is down 
Feb 20 11:28:35 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:363): Abort command issued -- 1 72140 2002.
Feb 20 11:28:37 sccmsdoc2 multipathd: sdd: tur checker reports path is up 
Feb 20 11:28:37 sccmsdoc2 multipathd: 8:48: reinstated 
Feb 20 11:28:37 sccmsdoc2 multipathd: mpath44: queue_if_no_path enabled 
Feb 20 11:28:37 sccmsdoc2 multipathd: mpath44: Recovered to normal mode 
Feb 20 11:28:37 sccmsdoc2 multipathd: mpath44: remaining active paths: 1 
Feb 20 11:28:37 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:28:37 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:28:38 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:28:38 sccmsdoc2 kernel: sd 14:0:1:2: SCSI error: return code = 0x00020000
Feb 20 11:28:38 sccmsdoc2 kernel: end_request: I/O error, dev sdd, sector 184
Feb 20 11:28:38 sccmsdoc2 kernel: device-mapper: multipath: Failing path 8:48.
Feb 20 11:28:38 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:28:38 sccmsdoc2 multipathd: 8:48: mark as failed 
Feb 20 11:28:38 sccmsdoc2 multipathd: mpath44: Entering recovery mode: max_retries=12 
Feb 20 11:28:38 sccmsdoc2 multipathd: mpath44: remaining active paths: 0 
Feb 20 11:28:42 sccmsdoc2 multipathd: sda: tur checker reports path is down 
Feb 20 11:28:42 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:456): Abort command issued -- 1 7221d 2002.
Feb 20 11:28:47 sccmsdoc2 multipathd: sdd: tur checker reports path is up 
Feb 20 11:28:47 sccmsdoc2 multipathd: 8:48: reinstated 
Feb 20 11:28:47 sccmsdoc2 multipathd: mpath44: queue_if_no_path enabled 
Feb 20 11:28:47 sccmsdoc2 multipathd: mpath44: Recovered to normal mode 
Feb 20 11:28:47 sccmsdoc2 multipathd: mpath44: remaining active paths: 1 
Feb 20 11:28:47 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:28:47 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:28:48 sccmsdoc2 kernel: sd 14:0:1:2: SCSI error: return code = 0x00020000
Feb 20 11:28:48 sccmsdoc2 kernel: end_request: I/O error, dev sdd, sector 184
Feb 20 11:28:48 sccmsdoc2 kernel: device-mapper: multipath: Failing path 8:48.
Feb 20 11:28:48 sccmsdoc2 multipathd: dm-12: add map (uevent) 
Feb 20 11:28:48 sccmsdoc2 multipathd: dm-12: devmap already registered 
Feb 20 11:28:48 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:477): Abort command issued -- 1 72264 2002.
Feb 20 11:28:48 sccmsdoc2 multipathd: 8:48: mark as failed 
Feb 20 11:28:48 sccmsdoc2 multipathd: mpath44: Entering recovery mode: max_retries=12 
Feb 20 11:28:48 sccmsdoc2 multipathd: mpath44: remaining active paths: 0 
Feb 20 11:28:52 sccmsdoc2 multipathd: sda: tur checker reports path is down 
Feb 20 11:28:54 sccmsdoc2 kernel: qla2xxx 0000:0b:00.0: scsi(14:1:477): Abort command issued -- 1 72267 2002.

Responses