SOLVED CAM status: SCSI Status Error ABORTED COMMAND NAK received

Status
Not open for further replies.

jasonboche

Dabbler
Joined
Oct 2, 2018
Messages
25
My newly assembled FreeNAS server gave up tonight and stopped providing storage to my VMware vSphere environment. The server remained powered on but didn't appear to have signs of life at the console and the HTTP UI page wasn't responding.

I powered the box off and then back on. Upon reboot, I was concerned to see hundreds of thousands of these message below fly by on the console. It doesn't appear to be any one single spinning disk.

After the FreeNAS box came back up, my virtual machines seem to be in tact and power on but I'm concerned about the stability as something doesn't seem right. Checking SAS cabling is on my to do list. I'm new to FreeNAS but have spent the better part of the last month reading and testing various build configurations. I thought everything was finally operationally ready but only got about 24 hours out of the box before it locked up tonight. If you have any comments or suggestions, I'm all ears. Thank you in advance.

Code:
Oct 28 20:54:31 freenas1 (da10:mps0:0:22:0): READ(10). CDB: 28 00 00 40 02 a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da10:mps0:0:22:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da10:mps0:0:22:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da10:mps0:0:22:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da10:mps0:0:22:0): Info: 0x400326
Oct 28 20:54:31 freenas1 (da10:mps0:0:22:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da8:mps0:0:20:0): READ(10). CDB: 28 00 00 40 00 a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da8:mps0:0:20:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da8:mps0:0:20:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da8:mps0:0:20:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da8:mps0:0:20:0): Info: 0x40012d
Oct 28 20:54:31 freenas1 (da8:mps0:0:20:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da7:mps0:0:15:0): READ(6). CDB: 08 00 00 a0 e0 00
Oct 28 20:54:31 freenas1 (da7:mps0:0:15:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da7:mps0:0:15:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da7:mps0:0:15:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da7:mps0:0:15:0): Info: 0xd3
Oct 28 20:54:31 freenas1 (da7:mps0:0:15:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da5:mps0:0:13:0): READ(10). CDB: 28 00 00 3f fc a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da5:mps0:0:13:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da5:mps0:0:13:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da5:mps0:0:13:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da5:mps0:0:13:0): Info: 0x3ffd6c
Oct 28 20:54:31 freenas1 (da5:mps0:0:13:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): READ(10). CDB: 28 00 00 3f fe a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): Info: 0x3fff6d
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): READ(10). CDB: 28 00 00 3f fe a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): Info: 0x3fff7f
Oct 28 20:54:31 freenas1 (da3:mps0:0:11:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da2:mps0:0:10:0): READ(10). CDB: 28 00 00 3f fc a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da2:mps0:0:10:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da2:mps0:0:10:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da2:mps0:0:10:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da2:mps0:0:10:0): Info: 0x3ffd6d
Oct 28 20:54:31 freenas1 (da2:mps0:0:10:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): READ(10). CDB: 28 00 00 3f fc a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): Info: 0x3ffd7f
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): Retrying command (per sense data)
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): READ(10). CDB: 28 00 00 3f fe a0 00 00 e0 00
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): CAM status: SCSI Status Error
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): SCSI status: Check Condition
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): SCSI sense: ABORTED COMMAND asc:4b,4 (NAK received)
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): Info: 0x3fff67
Oct 28 20:54:31 freenas1 (da1:mps0:0:9:0): Retrying command (per sense data)


These errors were also at the tail end of /var/log/messages after FreeNAS had been been successfully started with VMs running.
Code:
Oct 28 21:22:21 freenas1		(da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a6 fd 48 00 00 08 00 length 4096 SMID 424 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a6 fd 48 00 00 08 00
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): Retrying command
Oct 28 21:22:21 freenas1		(da14:mps0:0:27:0): SYNCHRONIZE CACHE(10). CDB: 35 00 00 00 00 00 00 00 00 00 length 0 SMID 717 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da14:mps0:0:27:0): SYNCHRONIZE CACHE(10). CDB: 35 00 00 00 00 00 00 00 00 00
Oct 28 21:22:21 freenas1 (da14:mps0:0:27:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da14:mps0:0:27:0): Retrying command
Oct 28 21:22:21 freenas1		(da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a6 fe 48 00 00 98 00 length 77824 SMID 243 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a6 fe 48 00 00 98 00
Oct 28 21:22:21 freenas1		(da5:mps0:0:13:0): READ(10). CDB: 28 00 16 d5 dc 98 00 00 08 00 length 4096 SMID 1006 terminated ioc 804b loginfo 3112010c sc(da15:mps0:0:28:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): Retrying command
Oct 28 21:22:21 freenas1 si 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da5:mps0:0:13:0): READ(10). CDB: 28 00 16 d5 dc 98 00 00 08 00
Oct 28 21:22:21 freenas1 (da5:mps0:0:13:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da5:mps0:0:13:0): Retrying command
Oct 28 21:22:21 freenas1		(da4:mps0:0:12:0): READ(10). CDB: 28 00 17 31 45 28 00 00 18 00 length 12288 SMID 614 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da4:mps0:0:12:0): READ(10). CDB: 28 00 17 31 45 28 00 00 18 00
Oct 28 21:22:21 freenas1		(da5:mps0:0:13:0): READ(10). CDB: 28 00 16 d5 dc 98 00 00 08 00 length 4096 SMID 662 terminated ioc 804b loginfo 3112010c scs(da4:mps0:0:12:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da4:mps0:0:12:0): Retrying command
Oct 28 21:22:21 freenas1 i 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da5:mps0:0:13:0): READ(10). CDB: 28 00 16 d5 dc 98 00 00 08 00
Oct 28 21:22:21 freenas1 (da5:mps0:0:13:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da5:mps0:0:13:0): Retrying command
Oct 28 21:22:21 freenas1		(da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a6 ff 48 00 01 00 00 length 131072 SMID 845 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a6 ff 48 00 01 00 00
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1		(da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a7 03 48 00 01 00 00 length 131072 SMID 372 terminated ioc 804b loginfo 3112010c(da15:mps0:0:28:0): Retrying command
Oct 28 21:22:21 freenas1 scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a7 03 48 00 01 00 00
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): Retrying command
Oct 28 21:22:21 freenas1		(da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a7 03 48 00 01 00 00 length 131072 SMID 452 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a7 03 48 00 01 00 00
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): Retrying command
Oct 28 21:22:21 freenas1		(da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a7 03 48 00 01 00 00 length 131072 SMID 592 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): WRITE(10). CDB: 2a 00 00 a7 03 48 00 01 00 00
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da15:mps0:0:28:0): Retrying command
Oct 28 21:22:21 freenas1		(da9:mps0:0:21:0): READ(10). CDB: 28 00 2b a0 37 a8 00 00 08 00 length 4096 SMID 585 terminated ioc 804b loginfo 3112010c scsi 0 state c xfer 0
Oct 28 21:22:21 freenas1 (da9:mps0:0:21:0): READ(10). CDB: 28 00 2b a0 37 a8 00 00 08 00
Oct 28 21:22:21 freenas1 (da9:mps0:0:21:0): CAM status: CCB request completed with an error
Oct 28 21:22:21 freenas1 (da9:mps0:0:21:0): Retrying command
Oct 28 21:23:08 freenas1		(da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 61 5e c5 c8 00 00 08 00 length 4096 SMID 251 Aborting command 0xfffffe0001a8f970
Oct 28 21:23:08 freenas1 mps0: Sending reset from mpssas_send_abort for target ID 12
Oct 28 21:23:08 freenas1 mps0: (da4:mps0:0:12:0): WRITE(10). CDB: 2a 00 61 5e c5 c8 00 00 08 00
Oct 28 21:23:08 freenas1 Unfreezing devq for target ID 12
Oct 28 21:23:08 freenas1 (da4:mps0:0:12:0): CAM status: Command timeout
Oct 28 21:23:08 freenas1 (da4:mps0:0:12:0): Retrying command

 

kdragon75

Wizard
Joined
Aug 7, 2016
Messages
2,457
We will need your full build details with layout of HBAs to HDDs, camcontrol devlist, zpool list -v, and glabel status.
At this point is sounds like a cable/HBA/backplane issue.
 

jasonboche

Dabbler
Joined
Oct 2, 2018
Messages
25
We will need your full build details with layout of HBAs to HDDs, camcontrol devlist, zpool list -v, and glabel status.
At this point is sounds like a cable/HBA/backplane issue.

HBA:Dell H310 6Gbps SAS HBA w/ LSI 9211-8i P20 IT Mode for ZFS FreeNAS unRAID
-SAS A cabled to SAS A on the 16 drive backplane of the Dell PowerEdge R720
-SAS B cabled to SAS B on the 16 drive backplane of the Dell PowerEdge R720

Output from the items you wanted to see:

Code:
root@freenas1:~ # camcontrol devlist
<PLDS DVD-ROM DS-8DBSH CD51>	   at scbus4 target 0 lun 0 (cd0,pass0)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 8 lun 0 (pass1,da0)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 9 lun 0 (pass2,da1)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 10 lun 0 (pass3,da2)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 11 lun 0 (pass4,da3)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 12 lun 0 (pass5,da4)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 13 lun 0 (pass6,da5)
<SEAGATE ST91000640SS AS0D>		at scbus6 target 14 lun 0 (pass7,da6)
<SEAGATE ST91000640SS AS0D>		at scbus6 target 15 lun 0 (pass8,da7)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 20 lun 0 (pass9,da8)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 21 lun 0 (pass10,da9)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 22 lun 0 (pass11,da10)
<SEAGATE ST91000640SS AS0B>		at scbus6 target 23 lun 0 (pass12,da11)
<SEAGATE ST300MM0006 LS06>		 at scbus6 target 25 lun 0 (pass13,da12)
<SEAGATE ST300MM0006 LS06>		 at scbus6 target 26 lun 0 (pass14,da13)
<TOSHIBA PX02SMF020 A3B3>		  at scbus6 target 27 lun 0 (pass15,da14)
<TOSHIBA PX02SMF020 A3B3>		  at scbus6 target 28 lun 0 (pass16,da15)
root@freenas1:~ #
root@freenas1:~ #
root@freenas1:~ # zpool list -v
NAME									 SIZE  ALLOC   FREE  EXPANDSZ   FRAG	CAP  DEDUP  HEALTH  ALTROOT
Mirror2x6x1TB_slog_pool				 5.44T   232G  5.21T		 -	 4%	 4%  1.00x  ONLINE  /mnt
  mirror								 928G  38.7G   889G		 -	 4%	 4%
	gptid/ea78618c-d871-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
	gptid/ee4ffbbd-d871-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
  mirror								 928G  39.3G   889G		 -	 5%	 4%
	gptid/f2241474-d871-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
	gptid/f5fde65e-d871-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
  mirror								 928G  38.1G   890G		 -	 4%	 4%
	gptid/fa136b66-d871-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
	gptid/fe104ae4-d871-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
  mirror								 928G  37.9G   890G		 -	 4%	 4%
	gptid/02101256-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
	gptid/061b3f08-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
  mirror								 928G  39.2G   889G		 -	 4%	 4%
	gptid/0a1e02b7-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
	gptid/0de30fdf-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
  mirror								 928G  38.5G   890G		 -	 4%	 4%
	gptid/11fcd307-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
	gptid/1630b300-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
log										 -	  -	  -		 -	  -	  -
  mirror								 184G   172K   184G		 -	 0%	 0%
	gptid/5eef4e53-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
	gptid/5fb3f0ee-d872-11e8-a516-b8ca3a5d20c8	  -	  -	  -		 -	  -	  -
freenas-boot							 278G   860M   277G		 -	  -	 0%  1.00x  ONLINE  -
  mirror								 278G   860M   277G		 -	  -	 0%
	da12p2								  -	  -	  -		 -	  -	  -
	da13p2								  -	  -	  -		 -	  -	  -
root@freenas1:~ #
root@freenas1:~ #
root@freenas1:~ # glabel status
									  Name  Status  Components
gptid/ea78618c-d871-11e8-a516-b8ca3a5d20c8	 N/A  da0p2
gptid/ee4ffbbd-d871-11e8-a516-b8ca3a5d20c8	 N/A  da1p2
gptid/f2241474-d871-11e8-a516-b8ca3a5d20c8	 N/A  da2p2
gptid/f5fde65e-d871-11e8-a516-b8ca3a5d20c8	 N/A  da3p2
gptid/fa136b66-d871-11e8-a516-b8ca3a5d20c8	 N/A  da4p2
gptid/fe104ae4-d871-11e8-a516-b8ca3a5d20c8	 N/A  da5p2
gptid/02101256-d872-11e8-a516-b8ca3a5d20c8	 N/A  da6p2
gptid/061b3f08-d872-11e8-a516-b8ca3a5d20c8	 N/A  da7p2
gptid/0a1e02b7-d872-11e8-a516-b8ca3a5d20c8	 N/A  da8p2
gptid/0de30fdf-d872-11e8-a516-b8ca3a5d20c8	 N/A  da9p2
gptid/11fcd307-d872-11e8-a516-b8ca3a5d20c8	 N/A  da10p2
gptid/1630b300-d872-11e8-a516-b8ca3a5d20c8	 N/A  da11p2
gptid/eb2aaeed-cce0-11e8-913d-b8ca3a5d20c8	 N/A  da12p1
gptid/eb5a974d-cce0-11e8-913d-b8ca3a5d20c8	 N/A  da13p1
gptid/5eef4e53-d872-11e8-a516-b8ca3a5d20c8	 N/A  da14p2
gptid/5fb3f0ee-d872-11e8-a516-b8ca3a5d20c8	 N/A  da15p2
gptid/f5bc3df1-d871-11e8-a516-b8ca3a5d20c8	 N/A  da3p1
gptid/f20b31fe-d871-11e8-a516-b8ca3a5d20c8	 N/A  da2p1
gptid/ee2126f6-d871-11e8-a516-b8ca3a5d20c8	 N/A  da1p1
gptid/ea52b5ef-d871-11e8-a516-b8ca3a5d20c8	 N/A  da0p1
root@freenas1:~ #


Referring to this post: https://forums.freenas.org/index.php?threads/scsi-status-errors.60353/#post-428372

Test: I completely removed the SAS B cable.
Result: Could not see any of the 16 drives.

Test: Replaced the above SAS B cable and completely removed the SAS A cable.
Result: Saw all 16 drives. The millions of SCSI errors I was previously seeing in /var/log/messages are now completely gone, even while running Iometer VM for hours on FreeNAS array.
Side effect: PowerEdge R720 throws an error about SAS A backplane cable being disconnected.

I looked for configurable BIOS settings on the Dell H310 6Gbps SAS HBA w/ LSI 9211-8i P20 IT Mode for ZFS FreeNAS unRAID HBA that might allow me to cable both SAS A and SAS B but didn't see anything closely related.
 

jasonboche

Dabbler
Joined
Oct 2, 2018
Messages
25
This appears to be resolved. Reseated all the SAS cables and the HBA itself and I'm no longer seeing the issue even with both SAS A and SAS B cables installed between the backplane and HBA. /var/log/messages is quiet as a church mouse.
 

kdragon75

Wizard
Joined
Aug 7, 2016
Messages
2,457
Sorry I didn't respond sooner but I'm glad it was a simple fix!
 
Status
Not open for further replies.
Top