SAS array is significantly slower than SATA on same hardware

[kristin]

What could cause an array of SAS drives to be almost 10x slower than an array of SATA drives within the same system?

Supermicro H8SGL w/ Opteron 6276
128GB of ECC DDR3
2x 9211-8i controllers with current firmware
TrueNAS-12.0-U7

I have two raid-z2 storage pools:

Show : zpool status

# zpool status
pool: freenas-boot
state: ONLINE
scan: scrub repaired 0B in 00:00:24 with 0 errors on Sun Feb 27 03:45:24 2022
config:

NAME STATE READ WRITE CKSUM
freenas-boot ONLINE 0 0 0
ada0p2 ONLINE 0 0 0

errors: No known data errors

pool: storage2
state: ONLINE
scan: scrub canceled on Thu Mar 3 16:36:14 2022
config:

NAME STATE READ WRITE CKSUM
storage2 ONLINE 0 0 0
raidz2-0 ONLINE 0 0 0
gptid/219f432f-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0
gptid/21e18eff-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0
gptid/2284d6e5-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0
gptid/2454410c-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0
gptid/23d5ceba-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0
gptid/2463c67a-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0
gptid/24d72c55-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0
gptid/24ca10c8-be29-11ea-92eb-001b217f0e7e ONLINE 0 0 0

errors: No known data errors

pool: storagetest
state: ONLINE
config:

NAME STATE READ WRITE CKSUM
storagetest ONLINE 0 0 0
raidz2-0 ONLINE 0 0 0
gptid/1aec00f5-9b4b-11ec-9147-00259028b247 ONLINE 0 0 0
gptid/1b58136d-9b4b-11ec-9147-00259028b247 ONLINE 0 0 0
gptid/1b281ceb-9b4b-11ec-9147-00259028b247 ONLINE 0 0 0
gptid/1b6afc58-9b4b-11ec-9147-00259028b247 ONLINE 0 0 0
gptid/1b1e30b4-9b4b-11ec-9147-00259028b247 ONLINE 0 0 0
gptid/1b04bab0-9b4b-11ec-9147-00259028b247 ONLINE 0 0 0
gptid/1b4ff0f1-9b4b-11ec-9147-00259028b247 ONLINE 0 0 0

errors: No known data errors
#

The 8-drive RAID-Z2 (storage2) is using Toshiba MG07SCA12TE and manages about 250MByte/sec writes.
The 7-drive RAID-Z2 (storagetest) is using WD Red WD60EFRX and manages about 1.9GByte/sec writes.

Show : benchmarks

# pwd
/mnt/storage2
# time dd if=/dev/zero of=10Gtest bs=1M count=10000
10000+0 records in
10000+0 records out
10485760000 bytes transferred in 29.908342 secs (350596499 bytes/sec)

real 0m29.926s
user 0m0.008s
sys 0m10.302s
# time dd if=/dev/zero of=100Gtest bs=1M count=100000

100000+0 records in
100000+0 records out
104857600000 bytes transferred in 424.861911 secs (246803955 bytes/sec)

real 7m4.864s
user 0m0.313s
sys 1m35.891s
# cd ../storagetest/
# time dd if=/dev/zero of=10Gtest bs=1M count=10000
10000+0 records in
10000+0 records out
10485760000 bytes transferred in 6.058714 secs (1730690797 bytes/sec)

real 0m6.061s
user 0m0.000s
sys 0m6.046s
# time dd if=/dev/zero of=100Gtest bs=1M count=100000
100000+0 records in
100000+0 records out
104857600000 bytes transferred in 54.058894 secs (1939691926 bytes/sec)

real 0m54.062s
user 0m0.118s
sys 0m53.934s
#

The drives are interleaved with each other on the same backplanes using the same cabling to the same controllers:

Show : Full mpsutil output

# mpsutil -u 0 show all
Adapter:
mps0 Adapter:
Board Name: SAS9211-8i
Board Assembly:
Chip Name: LSISAS2008
Chip Revision: ALL
BIOS Revision: 7.39.02.00
Firmware Revision: 20.00.07.00
Integrated RAID: no
SATA NCQ: ENABLED
PCIe Width/Speed: x8 (5.0 GB/sec)
IOC Speed: Full
Temperature: Unknown/Unsupported

PhyNum CtlrHandle DevHandle Disabled Speed Min Max Device
0 0001 0009 N 6.0 1.5 6.0 SAS Initiator
1 0005 000d N 6.0 1.5 6.0 SAS Initiator
2 0002 000a N 6.0 1.5 6.0 SAS Initiator
3 0006 000e N 6.0 1.5 6.0 SAS Initiator
4 0003 000b N 6.0 1.5 6.0 SAS Initiator
5 0007 000f N 6.0 1.5 6.0 SAS Initiator
6 0004 000c N 6.0 1.5 6.0 SAS Initiator
7 0008 0010 N 6.0 1.5 6.0 SAS Initiator

Devices:
B____T SAS Address Handle Parent Device Speed Enc Slot Wdt
00 00 4433221100000000 0009 0001 SATA Target 6.0 0001 03 1
00 01 4433221102000000 000a 0002 SATA Target 6.0 0001 01 1
00 16 5000039a18282076 000b 0003 SAS Target 6.0 0001 07 1
00 17 5000039a3800f8aa 000c 0004 SAS Target 6.0 0001 05 1
00 14 5000039a182964b2 000d 0005 SAS Target 6.0 0001 02 1
00 15 5000039a18296bae 000e 0006 SAS Target 6.0 0001 00 1
00 06 4433221105000000 000f 0007 SATA Target 6.0 0001 06 1
00 05 4433221107000000 0010 0008 SATA Target 6.0 0001 04 1

Enclosures:
Slots Logical ID SEPHandle EncHandle Type
08 500605b0022477f0 0001 Direct Attached SGPIO

Expanders:
NumPhys SAS Address DevHandle Parent EncHandle SAS Level

# mpsutil -u 1 show all
Adapter:
mps1 Adapter:
Board Name: SAS9211-8i
Board Assembly:
Chip Name: LSISAS2008
Chip Revision: ALL
BIOS Revision: 7.39.02.00
Firmware Revision: 20.00.07.00
Integrated RAID: no
SATA NCQ: ENABLED
PCIe Width/Speed: x8 (5.0 GB/sec)
IOC Speed: Full
Temperature: Unknown/Unsupported

PhyNum CtlrHandle DevHandle Disabled Speed Min Max Device
0 0001 0009 N 6.0 1.5 6.0 SAS Initiator
1 0003 000b N 6.0 1.5 6.0 SAS Initiator
2 0004 000c N 6.0 1.5 6.0 SAS Initiator
3 0002 000a N 6.0 1.5 6.0 SAS Initiator
4 N 1.5 6.0 SAS Initiator
5 0005 000d N 6.0 1.5 6.0 SAS Initiator
6 0007 000f N 6.0 1.5 6.0 SAS Initiator
7 0006 000e N 6.0 1.5 6.0 SAS Initiator

Devices:
B____T SAS Address Handle Parent Device Speed Enc Slot Wdt
00 11 5000039a18296916 0009 0001 SAS Target 6.0 0001 03 1
00 10 4433221103000000 000a 0002 SATA Target 6.0 0001 00 1
00 02 4433221101000000 000b 0003 SATA Target 6.0 0001 02 1
00 12 5000039a18027e82 000c 0004 SAS Target 6.0 0001 01 1
00 13 5000039a3800f8ca 000d 0005 SAS Target 6.0 0001 06 1
00 14 5000039a18296a86 000e 0006 SAS Target 6.0 0001 04 1
00 03 4433221106000000 000f 0007 SATA Target 6.0 0001 05 1

Enclosures:
Slots Logical ID SEPHandle EncHandle Type
08 500605b00229f4b0 0001 Direct Attached SGPIO

Expanders:
NumPhys SAS Address DevHandle Parent EncHandle SAS Level

#

I only noticed this because (like many others) I've been seeing a whole world of CAM timeouts and controller resets after upgrading from an older FreeNAS release:

Show : CAM timeouts in dmesg

(da7:mps0:0:17:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 48 00 00 00 08 00 00 length 4096 SMID 157 Command timeout on target 17(0x000e) 60000 set, 60.167777247 elapsed
mps0: Sending abort to target 17 for SMID 157
(da7:mps0:0:17:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 48 00 00 00 08 00 00 length 4096 SMID 157 Aborting command 0xfffffe014c08f2f8
(da7:mps0:0:17:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 80 48 00 00 01 00 00 00 length 131072 SMID 2057 Command timeout on target 17(0x000e) 60000 set, 60.168352536 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 80 a0 00 00 00 28 00 00 length 20480 SMID 2096 Command timeout on target 14(0x000b) 60000 set, 60.173534450 elapsed
mps0: Sending abort to target 14 for SMID 2096
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 80 a0 00 00 00 28 00 00 length 20480 SMID 2096 Aborting command 0xfffffe014c132080
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 80 70 00 00 00 28 00 00 length 20480 SMID 737 Command timeout on target 14(0x000b) 60000 set, 60.174151564 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 7f e8 00 00 00 30 00 00 length 24576 SMID 403 Command timeout on target 14(0x000b) 60000 set, 60.174756945 elapsed
(da7:mps0:0:17:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 7f f0 00 00 00 28 00 00 length 20480 SMID 89 Command timeout on target 17(0x000e) 60000 set, 60.175081860 elapsed
(da5:mps0:0:15:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 82 08 00 00 00 58 00 00 length 45056 SMID 593 Command timeout on target 15(0x000c) 60000 set, 60.162579159 elapsed
mps0: Sending abort to target 15 for SMID 593
(da5:mps0:0:15:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 82 08 00 00 00 58 00 00 length 45056 SMID 593 Aborting command 0xfffffe014c0b3cd8
(da0:mps0:0:0:0): WRITE(10). CDB: 2a 00 17 65 12 10 00 00 80 00 length 65536 SMID 347 Command timeout on target 0(0x0009) 60000 set, 60.163107519 elapsed
mps0: Sending abort to target 0 for SMID 347
(da0:mps0:0:0:0): WRITE(10). CDB: 2a 00 17 65 12 10 00 00 80 00 length 65536 SMID 347 Aborting command 0xfffffe014c09f248
(da0:mps0:0:0:0): WRITE(10). CDB: 2a 00 17 65 11 10 00 01 00 00 length 131072 SMID 580 Command timeout on target 0(0x0009) 60000 set, 60.163522835 elapsed
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 d8 00 00 00 30 00 00 length 24576 SMID 1259 Command timeout on target 16(0x000d) 60000 set, 60.163990753 elapsed
mps0: Sending abort to target 16 for SMID 1259
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 d8 00 00 00 30 00 00 length 24576 SMID 1259 Aborting command 0xfffffe014c0ebbc8
(da5:mps0:0:15:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 e0 00 00 00 28 00 00 length 20480 SMID 1802 Command timeout on target 15(0x000c) 60000 set, 60.164551338 elapsed
(da5:mps0:0:15:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 b0 00 00 00 28 00 00 length 20480 SMID 413 Command timeout on target 15(0x000c) 60000 set, 60.164939240 elapsed
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 b0 00 00 00 28 00 00 length 20480 SMID 1493 Command timeout on target 16(0x000d) 60000 set, 60.165249517 elapsed
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 80 00 00 00 28 00 00 length 20480 SMID 591 Command timeout on target 16(0x000d) 60000 set, 60.165663109 elapsed
(da7:mps0:0:17:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 58 00 00 00 28 00 00 length 20480 SMID 1905 Command timeout on target 17(0x000e) 60000 set, 60.166244439 elapsed
(da2:mps0:0:5:0): WRITE(10). CDB: 2a 00 17 65 10 b8 00 00 c8 00 length 102400 SMID 1142 Command timeout on target 5(0x0010) 60000 set, 60.167286971 elapsed
mps0: Sending abort to target 5 for SMID 1142
(da2:mps0:0:5:0): WRITE(10). CDB: 2a 00 17 65 10 b8 00 00 c8 00 length 102400 SMID 1142 Aborting command 0xfffffe014c0e1e90
(da2:mps0:0:5:0): WRITE(10). CDB: 2a 00 17 65 0f b8 00 01 00 00 length 131072 SMID 660 Command timeout on target 5(0x0010) 60000 set, 60.167707588 elapsed
(da3:mps0:0:6:0): WRITE(10). CDB: 2a 00 17 65 10 78 00 00 60 00 length 49152 SMID 1921 Command timeout on target 6(0x000f) 60000 set, 60.168456563 elapsed
mps0: Sending abort to target 6 for SMID 1921
(da3:mps0:0:6:0): WRITE(10). CDB: 2a 00 17 65 10 78 00 00 60 00 length 49152 SMID 1921 Aborting command 0xfffffe014c123558
(da1:mps0:0:1:0): WRITE(10). CDB: 2a 00 17 65 0f d8 00 01 00 00 length 131072 SMID 315 Command timeout on target 1(0x000a) 60000 set, 60.169116483 elapsed
mps0: Sending abort to target 1 for SMID 315
(da1:mps0:0:1:0): WRITE(10). CDB: 2a 00 17 65 0f d8 00 01 00 00 length 131072 SMID 315 Aborting command 0xfffffe014c09c748
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 28 00 00
mps0: (da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 3 more tries remain
mpssas_action_scsiio: Freezing devq for target ID 16
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 30 00 00
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): Retrying command, 3 more tries remain
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 87 c8 00 00 00 e8 00 00 length 118784 SMID 461 Command timeout on target 14(0x000b) 60000 set, 60.106195386 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 86 c8 00 00 01 00 00 00 length 131072 SMID 1137 Command timeout on target 14(0x000b) 60000 set, 60.106447745 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 85 c8 00 00 01 00 00 00 length 131072 SMID 918 Command timeout on target 14(0x000b) 60000 set, 60.106675748 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 84 c8 00 00 01 00 00 00 length 131072 SMID 1346 Command timeout on target 14(0x000b) 60000 set, 60.106901894 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 83 c8 00 00 01 00 00 00 length 131072 SMID 314 Command timeout on target 14(0x000b) 60000 set, 60.107127708 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 82 c8 00 00 01 00 00 00 length 131072 SMID 1940 Command timeout on target 14(0x000b) 60000 set, 60.107350844 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 81 c8 00 00 01 00 00 00 length 131072 SMID 1006 Command timeout on target 14(0x000b) 60000 set, 60.107576567 elapsed
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 43 a5 80 c8 00 00 01 00 00 00 length 131072 SMID 935 Command timeout on target 14(0x000b) 60000 set, 60.107808424 elapsed
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 30 00 00
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 28 00 00
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 2 more tries remain
(da6:mps0:0:16:0): Retrying command, 2 more tries remain
(da7:mps0:0:17:0): WRITE(16). CDB: 8a 00 00 00 00 02 48 c5 21 18 00 00 00 08 00 00 length 4096 SMID 1073 Command timeout on target 17(0x000e) 60000 set, 60.149998083 elapsed
(da5:mps0:0:15:0): WRITE(16). CDB: 8a 00 00 00 00 02 48 c5 21 18 00 00 00 08 00 00 length 4096 SMID 325 Command timeout on target 15(0x000c) 60000 set, 60.150308938 elapsed
(da4:mps0:0:14:0): WRITE(16). CDB: 8a 00 00 00 00 02 58 4c d3 08 00 00 00 08 00 00 length 4096 SMID 1933 Command timeout on target 14(0x000b) 60000 set, 60.150909098 elapsed
(da6:mps0:0:16:0): WRITE(16). CDB: 8a 00 00 00 00 02 58 4c d3 08 00 00 00 08 00 00 length 4096 SMID 1796 Command timeout on target 16(0x000d) 60000 set, 60.151243055 elapsed
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 30 00 00
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 28 00 00
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 1 more tries remain
(da6:mps0:0:16:0): Retrying command, 1 more tries remain
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 30 00 00
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 28 00 00
(da6:mps0:0:16:0): Retrying command, 0 more tries remain
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 0 more tries remain
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 28 00 00
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 02 58 41 03 c8 00 00 00 30 00 00
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): Error 5, Retries exhausted
(da4:mps0:0:14:0): Error 5, Retries exhausted
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
(da6:mps0:0:16:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
mps0: (da6:mps0:0:16:0): CAM status: CAM subsystem is busy
mpssas_action_scsiio: Freezing devq for target ID 14
(da6:mps0:0:16:0): Retrying command, 3 more tries remain
(da4:mps0:0:14:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 3 more tries remain
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
(da4:mps0:0:14:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da4:mps0:0:14:0): Retrying command, 2 more tries remain
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): Retrying command, 2 more tries remain
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da6:mps0:0:16:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da4:mps0:0:14:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 1 more tries remain
(da6:mps0:0:16:0): Retrying command, 1 more tries remain
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da6:mps0:0:16:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da6:mps0:0:16:0): Retrying command, 0 more tries remain
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 0 more tries remain
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
(da4:mps0:0:14:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): READ(10). CDB: 28 00 00 40 02 90 00 00 10 00
(da4:mps0:0:14:0): Error 5, Retries exhausted
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): Error 5, Retries exhausted
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 05 74 ff fa 90 00 00 00 10 00 00
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 05 74 ff fa 90 00 00 00 10 00 00
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 3 more tries remain
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da6:mps0:0:16:0): Retrying command, 3 more tries remain
mps0: mpssas_action_scsiio: Freezing devq for target ID 16
mps0: mpssas_action_scsiio: Freezing devq for target ID 14
(da6:mps0:0:16:0): READ(16). CDB: 88 00 00 00 00 05 74 ff fa 90 00 00 00 10 00 00
(da6:mps0:0:16:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): READ(16). CDB: 88 00 00 00 00 05 74 ff fa 90 00 00 00 10 00 00
(da6:mps0:0:16:0): Retrying command, 2 more tries remain
(da4:mps0:0:14:0): CAM status: CAM subsystem is busy
(da4:mps0:0:14:0): Retrying command, 2 more tries remain
(xpt0:mps0:0:1:0): SMID 8 task mgmt 0xfffffe014c082ac0 timed out
mps0: Reinitializing controller
mps0: Unfreezing devq for target ID 17
mps0: Unfreezing devq for target ID 14
mps0: Unfreezing devq for target ID 15
mps0: Unfreezing devq for target ID 0
mps0: Unfreezing devq for target ID 16
mps0: Unfreezing devq for target ID 5
mps0: Unfreezing devq for target ID 6
mps0: Unfreezing devq for target ID 1
mps0: Firmware: 20.00.07.00, Driver: 21.02.00.00-fbsd
mps0: IOCCapabilities: 1285c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,EventReplay,HostDisc>

Nobody seems to know why these are happening so I figured I'd throw in some old (and ugly SMR!) SATA drives to make a test pool and experiment with SCALE instead - and I noticed this massive performance discrepancy which feels like it might be related. The older FreeNAS install ran for years with none of these errors, and while performance wasn't stellar it was certainly better than what I'm seeing now.

Any suggestions, or should I just give up and migrate to SCALE?

 

[jgreco]

What's WCE set to on modepage 0x08?

 

[kristin]

# for i in {0..14} ; do camcontrol modepage da$i -m 8 | grep WCE; done;
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1
WCE: 1