The following multipaths are not optimal

[Itamar Croitoru]

Hi,

I've got two servers running FreeNAS 9.10 in production providing iSCSI for my VMware vCenter. One has larger slower disks for capacity storage and the other has smaller high speed disks for performance needs.

I got a Critical Alert by Email from the build running high speed disks the other day:

Code:

The following multipaths are not optimal: disk5, disk4

After having logged into the GUI, I noticed this alert was showing up there too. I checked the log and saw some details that I did not understand and sure enough, they were Emailed to me the next day:
freenas.hecint.com kernel log messages:
> (da37:mps0:0:46:0): WRITE(10). CDB: 2a 00 01 b7 a2 d4 00 00 01 00
> (da36:mps0:0:45:0): WRITE(10). CDB: 2a 00 01 b7 a2 d3 00 00 01 00
> (da37:mps0:0:46:0): CAM status: SCSI Status Error
> (da36:mps0:0:45:0): CAM status: SCSI Status Error
> (da37:mps0:0:46:0): SCSI status: Check Condition
> (da36:mps0:0:45:0): SCSI status: Check Condition
> (da37:mps0:0:46:0): SCSI sense: UNIT ATTENTION asc:29,1 (Power on
> occurred)
> (da36:mps0:0:45:0): SCSI sense: UNIT ATTENTION asc:29,1 (Power on
> occurred)
> (da37:mps0:0:46:0): Field Replaceable Unit: 1
> (da36:mps0:0:45:0): Field Replaceable Unit: 1
> (da37:(da36:mps0:0:mps0:0:46:45:0): 0): Retrying command (per sense
> data) Retrying command (per sense data)
> (da35:mps0:0:44:0): WRITE(10). CDB: 2a 00 01 b7 a2 d3 00 00 01 00
> (da35:mps0:0:44:0): CAM status: SCSI Status Error
> (da35:mps0:0:44:0): SCSI status: Check Condition
> (da35:mps0:0:44:0): SCSI sense: UNIT ATTENTION asc:29,1 (Power on
> occurred)
> (da35:mps0:0:44:0): Field Replaceable Unit: 1
> (da35:mps0:0:44:0): Retrying command (per sense data)
> (da37:mps0:0:46:0): WRITE(10). CDB: 2a 00 01 b7 a2 d4 00 00 01 00
> (da37:mps0:0:46:0): CAM status: SCSI Status Error
> (da36:mps0:0:45:0): WRITE(10). CDB: 2a 00 01 b7 a2 d3 00 00 01 00
> (da37:mps0:0:46:0): SCSI status: Check Condition
> (da36:mps0:0:45:0): CAM status: SCSI Status Error
> (da37:mps0:0:46:0): SCSI sense: NOT READY asc:4,1 (Logical unit is in
> process of becoming ready)
> (da36:mps0:0:45:0): SCSI status: Check Condition
> (da37:(da36:mps0:0:45:0): SCSI sense: NOT READY asc:4,1 (Logical unit
> is in process of becoming ready)
> mps0:0:(da36:46:mps0:0:0): 45:Polling device for readiness
> 0): Polling device for readiness
> (da35:mps0:0:44:0): WRITE(10). CDB: 2a 00 01 b7 a2 d3 00 00 01 00
> (da35:mps0:0:44:0): CAM status: SCSI Status Error
> (da35:mps0:0:44:0): SCSI status: Check Condition
> (da35:mps0:0:44:0): SCSI sense: NOT READY asc:4,1 (Logical unit is in
> process of becoming ready)
> (da35:mps0:0:44:0): Polling device for readiness
> (da27:mps0:0:36:0): WRITE(10). CDB: 2a 00 09 57 5c b8 00 00 08 00
> (da27:mps0:0:36:0): CAM status: SCSI Status Error
> (da27:mps0:0:36:0): SCSI status: Check Condition
> (da27:mps0:0:36:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da27:mps0:0:36:0): Retrying command (per sense data)
> (da26:mps0:0:35:0): WRITE(10). CDB: 2a 00 09 57 5c b0 00 00 08 00
> (da26:mps0:0:35:0): CAM status: SCSI Status Error
> (da26:mps0:0:35:0): SCSI status: Check Condition
> (da26:mps0:0:35:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da26:mps0:0:35:0): Retrying command (per sense data)
> (da28:mps0:0:37:0): WRITE(10). CDB: 2a 00 09 4e f0 08 00 00 60 00
> (da28:mps0:0:37:0): CAM status: SCSI Status Error
> (da28:mps0:0:37:0): SCSI status: Check Condition
> (da28:mps0:0:37:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da28:mps0:0:37:0): Retrying command (per sense data)
> (da30:mps0:0:39:0): WRITE(10). CDB: 2a 00 09 4e f0 08 00 00 60 00
> (da30:mps0:0:39:0): CAM status: SCSI Status Error
> (da30:mps0:0:39:0): SCSI status: Check Condition
> (da30:mps0:0:39:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da30:mps0:0:39:0): Retrying command (per sense data)
> (da20:mps0:0:29:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da20:mps0:0:29:0): CAM status: SCSI Status Error
> (da20:mps0:0:29:0): SCSI status: Check Condition
> (da20:mps0:0:29:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da20:mps0:0:29:0): Retrying command (per sense data)
> (da32:mps0:0:41:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 940 terminated ioc 804b scsi 0 state c xfer 0
> (da32:mps0:0:41:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da32:mps0:0:41:0): CAM status: CCB request completed with an error
> (da32:mps0:0:41:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 878 terminated ioc 804b scsi 0 state c xfer 0
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da32:mps0:0:41:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da32:mps0:0:41:0): CAM status: SCSI Status Error
> (da31:(da32:mps0:0:41:0): SCSI status: Check Condition
> mps0:0:(da32:mps0:0:41:0): SCSI sense: UNIT ATTENTION asc:29,2 (SCSI
> bus reset occurred)
> 40:0): Retrying command
> (da32:mps0:0:41:0): Field Replaceable Unit: 23
> (da32:mps0:0:41:0): Retrying command (per sense data)
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 513 terminated ioc 804b scsi 0 state c xfer 0
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da34:mps0:0:43:0): CAM status: CCB request completed with an error
> (da34:mps0:0:43:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 259 terminated ioc 804b scsi 0 state c xfer 0
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da31:mps0:0:40:0): Retrying command
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 841 terminated ioc 804b scsi 0 state c xfer 0
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da34:mps0:0:43:0): CAM status: CCB request completed with an error
> (da34:mps0:0:43:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 226 terminated ioc 804b scsi 0 state c xfer 0
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da31:mps0:0:40:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 827 terminated ioc 804b scsi 0 state c xfer 0
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da31:mps0:0:40:0): CAM status: CCB request completed with an erro
> (da31:mps0:0:40:0): Retrying command
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 593 terminated ioc 804b scsi 0 state c xfer 0
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da34:mps0:0:43:0): CAM status: CCB request completed with an error
> (da34:mps0:0:43:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 290 terminated ioc 804b scsi 0 state c xfer 0
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da31:mps0:0:40:0): Error 5, Retries exhausted
> GEOM_MULTIPATH: Error 5, da31 in disk5 marked FAIL
> GEOM_MULTIPATH: da4 is now active path in disk5
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 787 terminated ioc 804b scsi 0 state c xfer 0
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da34:mps0:0:43:0): CAM status: CCB request completed with an error
> (da34:mps0:0:43:0): Retrying command
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 905 terminated ioc 804b scsi 0 state c xfer 0
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da4:mps0:0:12:0): CAM status: CCB request completed with an error
> (da4:mps0:0:12:0): Retrying command
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 929 terminated ioc 804b scsi 0 state c xfer 0
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da34:mps0:0:43:0): CAM status: CCB request completed with an error
> (da34:mps0:0:43:0): Error 5, Retries exhausted
> GEOM_MULTIPATH: Error 5, da34 in disk4 marked FAIL
> GEOM_MULTIPATH: da3 is now active path in disk4
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 930 terminated ioc 804b scsi 0 state c xfer 0
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da4:mps0:0:12:0): CAM status: CCB request completed with an error
> (da4:mps0:0:12:0): Retrying command
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 836 terminated ioc 804b scsi 0 state c xfer 0
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da4:mps0:0:12:0): CAM status: CCB request completed with an error
> (da4:mps0:0:12:0): Retrying command
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 624 terminated ioc 804b scsi 0 state c xfer 0
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da3:mps0:0:11:0): CAM status: CCB request completed with an error
> (da3:mps0:0:11:0): Retrying command
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 698 terminated ioc 804b scsi 0 state c xfer 0
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da4:mps0:0:12:0): CAM status: CCB request completed with an error
> (da4:mps0:0:12:0): Retrying command
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 902 terminated ioc 804b scsi 0 state c xfer 0
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da3:mps0:0:11:0): CAM status: CCB request completed with an error
> (da3:mps0:0:11:0): Retrying command
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> length 69632 SMID 755 terminated ioc 804b scsi 0 state c xfer 0
> (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 0a 63 5a 78 00 00 88 00
> (da4:mps0:0:12:0): CAM status: CCB request completed with an error
> (da4:mps0:0:12:0): Error 5, Retries exhausted
> GEOM_MULTIPATH: Error 5, da4 in disk5 marked FAIL
> GEOM_MULTIPATH: all paths in disk5 were marked FAIL, restore da31
> GEOM_MULTIPATH: da31 is now active path in disk5
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 499 terminated ioc 804b scsi 0 state c xfer 0
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da3:mps0:0:11:0): CAM status: CCB request completed with an error
> (da3:mps0:0:11:0): Retrying command
> (da31:mp0:0:40:0): READ(10). CDB: 28 00 11 17 70 90 00 00 10 00 length 8192 SMID 355 terminated ioc 804b scsi 0 state c xfer 0
> (da31:mps0:0:40:0): READ(10). CDB: 28 00 11 17 6e 90 00 00 10 00
> length 8192 SMID 741 terminated ioc 804b scsi 0 state c
> xfer(da31:mps0:0:40:0): READ(10). CDB: 28 00 11 17 70 90 00 00 10 00
> 0
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da31:mps0:0:40:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
> length 8192 SMID 386 terminated ioc 804b scsi 0 state c xfer(da31: 0
> mps0:0:40:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5b 00 00 00 c0 00
> length 98304 SMID 260 terminated ioc 804b scsi 0 state c
> xf(da31:mps0:0:40:0): READ(10). CDB: 28 00 11 17 6e 90 00 00 10 00 er
> 0
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da31:mps0:0:40:0): Retrying command
> (da31:mps0:0:40:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da31:mps0:0:40:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5b 00 00 00 c0 00
> (da31:mps0:0:40:0): CAM status: CCB request completed with an error
> (da31:mps0:0:40:0): Retrying command
> (da31:mps0:0:40:0): WRITE(10). CDB: 2a 00 0a 63 5b 00 00 00 c0 00
> (da31:mps0:0:40:0): CAM status: SCSI Status Error
> (da31:mps0:0:40:0): SCSI status: Check Condition
> (da31:mps0:0:40:0): SCSI sense: UNIT ATTENTION asc:29,2 (SCSI bus
> reset occurred)
> (da31:mps0:0:40:0): Retrying command (per sense data)
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> length 49152 SMID 909 terminated ioc 804b scsi 0 state c xfer 0
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da3:mps0:0:11:0): CAM status: CCB request completed with an error
> (da3:mps0:0:11:0): Retrying command
> (da3:mps0:0:11:0): WRITE(10). CDB: 2a 00 0e b9 aa a0 00 00 60 00
> (da3:mps0:0:11:0): CAM status: SCSI Status Error
> (da3:mps0:0:11:0): SCSI status: Check Condition
> (da3:mps0:0:11:0): SCSI sense: UNIT ATTENTION asc:29,2 (SCSI bus reset
> occurred)
> (da3:mps0:0:11:0): Error 5, Retries exhausted
> GEOM_MULTIPATH: Error 5, da3 in disk4 marked FAIL
> GEOM_MULTIPATH: all paths in disk4 were marked FAIL, restore da34
> GEOM_MULTIPATH: da34 is now active path in disk4
> (da34:mps0:0:43:0): WRITE(10). CDB: 2a 00 0e b9 ac 18 00 00 60 00
> (da34:mps0:0:43:0): CAM status: SCSI Status Error
> (da34:mps0:0:43:0): SCSI status: Check Condition
> (da34:mps0:0:43:0): SCSI sense: UNIT ATTENTION asc:29,2 (SCSI bus
> reset occurred)
> (da34:mps0:0:43:0): Retrying command (per sense data)
> (da33:mps0:0:42:0): WRITE(10). CDB: 2a 00 0e ae 6c 10 00 00 10 00
> (da33:mps0:0:42:0): CAM status: SCSI Status Error
> (da33:mps0:0:42:0): SCSI status: Check Condition
> (da33:mps0:0:42:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da24:mps0:0:33:0): WRITE(10). CDB: 2a 00 0a af b9 70 00 00 08 00
> (da33:mps0:0:42:0): Field Replaceable Unit: 115
> (da24:mps0:0:33:0): CAM status: SCSI Status Error
> (da33:(da24:mps0:0:33:0): SCSI status: Check Condition
> mps0:0:(da24:mps0:0:33:0): SCSI sense: UNIT ATTENTION asc:2f,1
> (Commands cleared by power loss notification)
> 42:(da24:mps0:0:33:0): Field Replaceable Unit: 115
> 0): (da24:Retrying command (per sense data)
> mps0:0:33:0): Retrying command (per sense data)
> (da29:mps0:0:38:0): WRITE(10). CDB: 2a 00 0e a5 a2 c0 00 00 08 00
> (da29:mps0:0:38:0): CAM status: SCSI Status Error
> (da29:mps0:0:38:0): SCSI status: Check Condition
> (da29:mps0:0:38:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da29:mps0:0:38:0): Field Replaceable Unit: 115
> (da29:mps0:0:38:0): Retrying command (per sense data)
> (da19:mps0:0:28:0): WRITE(10). CDB: 2a 00 0a af b9 70 00 00 08 00
> (da19:mps0:0:28:0): CAM status: SCSI Status Error
> (da19:mps0:0:28:0): SCSI status: Check Condition
> (da19:mps0:0:28:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da19:mps0:0:28:0): Retrying command (per sense data)
> (da23:mps0:0:32:0): WRITE(10). CDB: 2a 00 07 b9 c1 d0 00 00 08 00
> (da23:mps0:0:32:0): CAM status: SCSI Status Error
> (da23:mps0:0:32:0): SCSI status: Check Condition
> (da22:mps0:0:31:0): WRITE(10). CDB: 2a 00 09 de 91 68 00 00 08 00
> (da23:mps0:0:32:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da22:mps0:0:31:0): CAM status: SCSI Status Error
> (da23:(da22:mps0:0:31:0): SCSI status: Check Condition
> mps0:0:(da22:mps0:0:31:0): SCSI sense: UNIT ATTENTION asc:2f,1
> (Commands cleared by power loss notification)
> 32:(da22:0): mps0:0:Retrying command (per sense data)
> 31:0): Retrying command (per sense data)
> (da21:mps0:0:30:0): WRITE(10). CDB: 2a 00 09 de 91 68 00 00 08 00
> (da21:mps0:0:30:0): CAM status: SCSI Status Error
> (da21:mps0:0:30:0): SCSI status: Check Condition
> (da21:mps0:0:30:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da21:mps0:0:30:0): Retrying command (per sense data)
> (da25:mps0:0:34:0): WRITE(10). CDB: 2a 00 07 b9 c1 c8 00 00 08 00
> (da25:mps0:0:34:0): CAM status: SCSI Status Error
> (da25:mps0:0:34:0): SCSI status: Check Condition
> (da25:mps0:0:34:0): SCSI sense: UNIT ATTENTION asc:2f,1 (Commands
> cleared by power loss notification)
> (da25:mps0:0:34:0): Retrying command (per sense data)



I'm fairly new to working with FreeNAS, so I am asking for help to understand what the issue is. Here are the details about this unit:

• Build: FreeNAS-9.10.2-U4 (27ae72978)
• Server: Dell PowerEdge R310
• CPU: Intel(R) Xeon(R) CPU X3440 @ 2.53GHz
• RAM: 48 GB ECC 1333
• Boot drive: 60 GB Commercial SATA SSD
• Storage Controller: HP rebrand of LSI 9207-8E flashed with IT build
• Storage Array: Compelent 24 bay SAS array DAS
• Drives: 14 x 146 GB 15,000 RPM SAS drives
• zpool: 1 x RAID 10, 1 x RAID Z1
• Shared as iSCSI through 2 x Dell PowerConnect 6248 stacked switches
• Used as Datastores for 2 x VMware ESXi 5.5 Update 3e

Thinking so far:

• I thought that this may indicate a power surge got through my UPSes and caused something in all the drives.
• I checked SMART for all drives and they don't show any errors.
• Maybe the HBA is having issues but I'm not sure how to test without swapping it out.
• Since this server is production, that would have to wait for an outage window.

 

[dlavigne]

Were you able to figure this out?

 

[Itamar Croitoru]

Not as of yet. I have not seen the second Email with errors repeat though, so I'm thinking that it was a temporary issue with the HBA and a reboot will clear the error.

Unfortunately, to test this theory I would need to reboot. Since this iSCSI SAN is in production right now, that's not going to be an option for a few more months.

 

[Itamar Croitoru]

I was able to schedule some downtime for tonight and checked for updates. I processed the upgrade to FreeNAS-9.10.2-U5 and this included two reboots.

The errors have not yet come back. I will not call it fixed though unless the issue doesn't come back for a while.