On 07/07/11 13:13, Tim Small wrote: > 2x 2G Hitachi drives connected via a SiI 3726, and to the 88SE9125 card > ( Debian 6.0 2.6.32 NCQ depth 31 - same with any value between 2 and > 31 ) - works for simultaneous reads with hdparm - read speeds at 31M per > second on both drives. Reads from a single drive at between 19M per > second and 130M per second with NCQ depth = 31 (most often 130M), but > reads from a single drive with NCQ depth = 2 varied between 5M per > second and 54M per second. Reads from a single drive (direct to host, > not via PMP) at 130M per second (127M per second with depth = 2). > In the same machine, but with 2.6.38 (debian squeeze backports kernel): NCQ 31, two drives connected to 3726 behind the **88SE9125** : root@netboot:~# hdparm -t /dev/sdb /dev/sdb: Timing buffered disk reads: 386 MB in 3.00 seconds = 128.59 MB/sec root@netboot:~# hdparm -t /dev/sdc /dev/sdc: Timing buffered disk reads: 38 MB in 7.01 seconds = 5.42 MB/sec root@netboot:~# hdparm -t /dev/sdc /dev/sdc: Timing buffered disk reads: read(2097152) returned 823296 bytes BLKFLSBUF failed: No such device This coincides with the following dmesg: [ 102.880043] ata3.00: failed to read SCR 1 (Emask=0x40) [ 102.884798] ata3.01: failed to read SCR 1 (Emask=0x40) [ 102.889604] ata3.02: failed to read SCR 1 (Emask=0x40) [ 102.894352] ata3.03: failed to read SCR 1 (Emask=0x40) [ 102.899057] ata3.04: failed to read SCR 1 (Emask=0x40) [ 102.903730] ata3.05: failed to read SCR 1 (Emask=0x40) [ 102.908365] ata3.15: exception Emask 0x4 SAct 0x0 SErr 0x400000 action 0x6 frozen [ 102.913067] ata3.15: SError: { Handshk } [ 102.917727] ata3.00: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen [ 102.922460] ata3.01: exception Emask 0x100 SAct 0x7 SErr 0x0 action 0x6 frozen [ 102.927107] ata3.01: failed command: READ FPDMA QUEUED [ 102.931757] ata3.01: cmd 60/98:00:00:47:02/00:00:00:00:00/40 tag 0 ncq 77824 in [ 102.931761] res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) [ 102.941055] ata3.01: status: { DRDY } [ 102.945643] ata3.01: failed command: READ FPDMA QUEUED [ 102.950234] ata3.01: cmd 60/68:08:98:47:02/00:00:00:00:00/40 tag 1 ncq 53248 in [ 102.950238] res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) [ 102.959550] ata3.01: status: { DRDY } [ 102.964223] ata3.01: failed command: READ FPDMA QUEUED [ 102.968945] ata3.01: cmd 60/b8:10:48:46:02/00:00:00:00:00/40 tag 2 ncq 94208 in [ 102.968949] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) [ 102.978510] ata3.01: status: { DRDY } [ 102.983270] ata3.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen [ 102.988128] ata3.03: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen [ 102.992942] ata3.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen [ 102.997719] ata3.05: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen [ 103.002468] ata3.15: hard resetting link [ 103.720029] ata3.15: SATA link up 3.0 Gbps (SStatus 123 SControl 330) [ 103.725058] ata3.15: Port Multiplier vendor mismatch '0x1095' != '0x0' [ 103.729797] ata3.15: PMP revalidation failed (errno=-19) [ 108.724032] ata3.15: hard resetting link [ 109.444033] ata3.15: SATA link up 3.0 Gbps (SStatus 123 SControl 330) [ 109.448924] ata3.15: Port Multiplier vendor mismatch '0x1095' != '0x0' [ 109.453679] ata3.15: PMP revalidation failed (errno=-19) [ 109.458399] ata3.15: limiting SATA link speed to 1.5 Gbps [ 114.448029] ata3.15: hard resetting link [ 115.168034] ata3.15: SATA link up 1.5 Gbps (SStatus 113 SControl 310) [ 115.173007] ata3.15: Port Multiplier vendor mismatch '0x1095' != '0x0' [ 115.177781] ata3.15: PMP revalidation failed (errno=-19) [ 115.182541] ata3.15: failed to recover PMP after 5 tries, giving up [ 115.187291] ata3.15: Port Multiplier detaching [ 115.191959] ata3.00: disabled [ 115.196572] ata3.01: disabled [ 115.201115] ata3.00: disabled [ 120.172024] ata3: hard resetting link [ 120.892037] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 330) [ 120.896695] ata3.15: Port Multiplier 1.1, 0x1095:0x3726 r23, 6 ports, feat 0x1/0x9 [ 120.901169] ahci 0000:01:00.0: FBS is enabled. [ 120.905800] ata3.00: hard resetting link [ 121.228222] ata3.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320) [ 121.232855] ata3.01: hard resetting link [ 121.556224] ata3.01: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 121.560862] ata3.02: hard resetting link [ 121.884223] ata3.02: SATA link down (SStatus 0 SControl 320) [ 121.888866] ata3.03: hard resetting link [ 122.212222] ata3.03: SATA link down (SStatus 0 SControl 320) [ 122.216721] ata3.04: hard resetting link [ 122.540221] ata3.04: SATA link down (SStatus 0 SControl 320) [ 122.544633] ata3.05: hard resetting link [ 122.868232] ata3.05: SATA link up 1.5 Gbps (SStatus 113 SControl 320) [ 122.873827] ata3.00: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max UDMA/133 [ 122.878067] ata3.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32), AA [ 122.883669] ata3.00: configured for UDMA/133 [ 122.889185] ata3.01: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max UDMA/133 [ 122.893487] ata3.01: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32), AA [ 122.899114] ata3.01: configured for UDMA/133 [ 122.903547] ata3.01: device reported invalid CHS sector 0 [ 122.907930] ata3.01: device reported invalid CHS sector 0 [ 122.912322] ata3.01: device reported invalid CHS sector 0 [ 122.916715] sd 1:1:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 122.921135] sd 1:1:0:0: [sdc] Sense Key : Aborted Command [current] [descriptor] [ 122.925558] Descriptor sense data with sense descriptors (in hex): [ 122.929959] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 [ 122.934528] 00 00 00 00 [ 122.938953] sd 1:1:0:0: [sdc] Add. Sense: No additional sense information [ 122.943428] sd 1:1:0:0: [sdc] CDB: Read(10): 28 00 00 02 47 00 00 00 98 00 [ 122.947984] end_request: I/O error, dev sdc, sector 149248 [ 122.952425] Buffer I/O error on device sdc, logical block 18656 [ 122.956888] Buffer I/O error on device sdc, logical block 18657 [ 122.961268] Buffer I/O error on device sdc, logical block 18658 [ 122.965594] Buffer I/O error on device sdc, logical block 18659 [ 122.969830] Buffer I/O error on device sdc, logical block 18660 [ 122.974033] Buffer I/O error on device sdc, logical block 18661 [ 122.978172] Buffer I/O error on device sdc, logical block 18662 [ 122.982256] Buffer I/O error on device sdc, logical block 18663 [ 122.986239] Buffer I/O error on device sdc, logical block 18664 [ 122.990165] Buffer I/O error on device sdc, logical block 18665 [ 122.994116] sd 1:1:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 122.998160] sd 1:1:0:0: [sdc] Sense Key : Aborted Command [current] [descriptor] [ 123.002283] Descriptor sense data with sense descriptors (in hex): [ 123.006370] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 [ 123.010586] 00 00 00 00 [ 123.014657] sd 1:1:0:0: [sdc] Add. Sense: No additional sense information [ 123.018792] sd 1:1:0:0: [sdc] CDB: Read(10): 28 00 00 02 47 98 00 00 68 00 [ 123.023005] end_request: I/O error, dev sdc, sector 149400 [ 123.027149] sd 1:1:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 123.031332] sd 1:1:0:0: [sdc] Sense Key : Aborted Command [current] [descriptor] [ 123.035531] Descriptor sense data with sense descriptors (in hex): [ 123.039728] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 [ 123.044071] 00 00 00 00 [ 123.048263] sd 1:1:0:0: [sdc] Add. Sense: No additional sense information [ 123.052512] sd 1:1:0:0: [sdc] CDB: Read(10): 28 00 00 02 46 48 00 00 b8 00 [ 123.056830] end_request: I/O error, dev sdc, sector 149064 [ 123.061084] ata3: EH complete [ 123.065640] ata3.00: detaching (SCSI 1:0:0:0) [ 123.068043] sd 1:1:0:0: rejecting I/O to offline device [ 123.075042] sd 1:0:0:0: [sdb] Synchronizing SCSI cache [ 123.077512] sd 1:0:0:0: [sdb] Stopping disk [ 123.082745] sd 1:1:0:0: rejecting I/O to offline device [ 123.084984] end_request: I/O error, dev sdc, sector 0 [ 123.087925] sd 1:1:0:0: rejecting I/O to offline device [ 123.090124] end_request: I/O error, dev sdc, sector 0 [ 123.694656] ata3.01: detaching (SCSI 1:1:0:0) [ 123.703452] sd 1:1:0:0: [sdc] Synchronizing SCSI cache [ 123.707890] sd 1:1:0:0: [sdc] Stopping disk After reset - set NCQ depth to 1: root@netboot:~# find /sys -name queue_depth -print0 | xargs -0 -i sh -c "echo -n {}: ; echo 1 > {} ; cat {}" /sys/devices/pci0000:00/0000:00:01.0/0000:01:00.0/host1/target1:0:0/1:0:0:0/queue_depth:1 /sys/devices/pci0000:00/0000:00:01.0/0000:01:00.0/host1/target1:1:0/1:1:0:0/queue_depth:1 root@netboot:~# hdparm -t /dev/sdc /dev/sdc: Timing buffered disk reads: 380 MB in 3.01 seconds = 126.06 MB/sec root@netboot:~# hdparm -t /dev/sdc /dev/sdc: Timing buffered disk reads: 384 MB in 3.01 seconds = 127.47 MB/sec root@netboot:~# while true ; do hdparm -t /dev/sdb ; done /dev/sdb: Timing buffered disk reads: 388 MB in 3.01 seconds = 129.03 MB/sec /dev/sdb: Timing buffered disk reads: 394 MB in 3.01 seconds = 130.80 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.00 seconds = 130.57 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.01 seconds = 130.40 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.00 seconds = 130.46 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.01 seconds = 130.39 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.01 seconds = 130.43 MB/sec /dev/sdb: Timing buffered disk reads: 394 MB in 3.01 seconds = 130.80 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.00 seconds = 130.60 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.01 seconds = 130.42 MB/sec /dev/sdb: ^C [set NCQ back to 31:] root@netboot:~# find /sys -name queue_depth -print0 | xargs -0 -i sh -c "echo -n {}: ; echo 31 > {} ; cat {}" /sys/devices/pci0000:00/0000:00:01.0/0000:01:00.0/host1/target1:0:0/1:0:0:0/queue_depth:31 /sys/devices/pci0000:00/0000:00:01.0/0000:01:00.0/host1/target1:1:0/1:1:0:0/queue_depth:31 root@netboot:~# while true ; do hdparm -t /dev/sdb ; done /dev/sdb: Timing buffered disk reads: 328 MB in 3.55 seconds = 92.29 MB/sec /dev/sdb: Timing buffered disk reads: 204 MB in 5.30 seconds = 38.48 MB/sec /dev/sdb: Timing buffered disk reads: 376 MB in 3.01 seconds = 124.78 MB/sec /dev/sdb: Timing buffered disk reads: 200 MB in 3.01 seconds = 66.53 MB/sec /dev/sdb: Timing buffered disk reads: 276 MB in 3.01 seconds = 91.68 MB/sec /dev/sdb: Timing buffered disk reads: 154 MB in 3.36 seconds = 45.81 MB/sec /dev/sdb: Timing buffered disk reads: 384 MB in 3.01 seconds = 127.45 MB/sec /dev/sdb: Timing buffered disk reads: 358 MB in 3.01 seconds = 119.03 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.00 seconds = 130.65 MB/sec /dev/sdb: Timing buffered disk reads: 364 MB in 4.33 seconds = 84.11 MB/sec /dev/sdb: Timing buffered disk reads: 188 MB in 3.01 seconds = 62.44 MB/sec /dev/sdb: Timing buffered disk reads: 342 MB in 3.01 seconds = 113.47 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.01 seconds = 130.39 MB/sec /dev/sdb: Timing buffered disk reads: 394 MB in 3.01 seconds = 130.76 MB/sec /dev/sdb: Timing buffered disk reads: 274 MB in 3.91 seconds = 70.16 MB/sec /dev/sdb: Timing buffered disk reads: 392 MB in 3.00 seconds = 130.50 MB/sec Now it seems to work (no more resets), but performance does wander down to 45MB/sec For simultaneous reads for two drives behind an 3726 pmp on the 88SE9125 and NCQ=1 using 2.6.38: root@netboot:~# while true ; do sh -c "(hdparm -t /dev/sdb & hdparm -t /dev/sdc) 2>&1 | grep MB" ; done Timing buffered disk reads: 280 MB in 3.01 seconds = 93.05 MB/sec 280 MB in 3.01 seconds = 93.12 MB/sec Timing buffered disk reads: 284 MB in 3.01 seconds = 94.45 MB/sec 284 MB in 3.02 seconds = 94.11 MB/sec Timing buffered disk reads: 284 MB in 3.01 seconds = 94.39 MB/sec 284 MB in 3.02 seconds = 94.12 MB/sec Timing buffered disk reads: 284 MB in 3.01 seconds = 94.28 MB/sec 284 MB in 3.02 seconds = 94.07 MB/sec Timing buffered disk reads: 284 MB in 3.02 seconds = 94.19 MB/sec 284 MB in 3.02 seconds = 94.06 MB/sec Timing buffered disk reads: 284 MB in 3.01 seconds = 94.32 MB/sec 284 MB in 3.02 seconds = 94.18 MB/sec Timing buffered disk reads: 284 MB in 3.01 seconds = 94.24 MB/sec 284 MB in 3.01 seconds = 94.24 MB/sec Timing buffered disk reads: 284 MB in 3.02 seconds = 94.17 MB/sec 284 MB in 3.01 seconds = 94.28 MB/sec Timing buffered disk reads: 284 MB in 3.02 seconds = 94.10 MB/sec 284 MB in 3.02 seconds = 94.08 MB/sec Timing buffered disk reads: 284 MB in 3.01 seconds = 94.31 MB/sec 284 MB in 3.01 seconds = 94.21 MB/sec Timing buffered disk reads: 284 MB in 3.02 seconds = 94.05 MB/sec 284 MB in 3.02 seconds = 94.12 MB/sec Timing buffered disk reads: 284 MB in 3.01 seconds = 94.23 MB/sec 284 MB in 3.01 seconds = 94.24 MB/sec ... so faster than 2.6.32, and consistent. For NCQ=31: root@netboot:~# while true ; do sh -c "(hdparm -t /dev/sdb & hdparm -t /dev/sdc) 2>&1 | grep MB" ; done Timing buffered disk reads: 276 MB in 3.02 seconds = 91.37 MB/sec 276 MB in 3.02 seconds = 91.52 MB/sec Timing buffered disk reads: 278 MB in 3.01 seconds = 92.31 MB/sec 278 MB in 3.01 seconds = 92.46 MB/sec Timing buffered disk reads: 268 MB in 3.00 seconds = 89.31 MB/sec 268 MB in 3.00 seconds = 89.32 MB/sec Timing buffered disk reads: 278 MB in 3.00 seconds = 92.61 MB/sec 278 MB in 3.01 seconds = 92.31 MB/sec Timing buffered disk reads: 194 MB in 3.02 seconds = 64.27 MB/sec 194 MB in 3.02 seconds = 64.24 MB/sec Timing buffered disk reads: 260 MB in 3.00 seconds = 86.55 MB/sec 260 MB in 3.00 seconds = 86.61 MB/sec Timing buffered disk reads: 278 MB in 3.01 seconds = 92.36 MB/sec 278 MB in 3.02 seconds = 92.20 MB/sec Timing buffered disk reads: 248 MB in 3.02 seconds = 82.23 MB/sec 248 MB in 3.01 seconds = 82.39 MB/sec Timing buffered disk reads: 268 MB in 3.00 seconds = 89.21 MB/sec 268 MB in 3.01 seconds = 89.09 MB/sec Timing buffered disk reads: 278 MB in 3.01 seconds = 92.44 MB/sec 278 MB in 3.01 seconds = 92.45 MB/sec Timing buffered disk reads: 280 MB in 3.02 seconds = 92.83 MB/sec 280 MB in 3.02 seconds = 92.61 MB/sec Timing buffered disk reads: 274 MB in 3.02 seconds = 90.77 MB/sec 274 MB in 3.02 seconds = 90.81 MB/sec ... a little slower, and with some strange performance dips (e.g. the 65M figure). After all this, I tried a "smartctl -x /dev/sd[bc]" and got this for sdb: SATA Phy Event Counters (GP Log 0x11) ID Size Value Description 0x0001 2 0 Command failed due to ICRC error 0x0002 2 0 R_ERR response for data FIS 0x0003 2 0 R_ERR response for device-to-host data FIS 0x0004 2 0 R_ERR response for host-to-device data FIS 0x0005 2 0 R_ERR response for non-data FIS 0x0006 2 0 R_ERR response for device-to-host non-data FIS 0x0007 2 0 R_ERR response for host-to-device non-data FIS 0x0009 2 26 Transition from drive PhyRdy to drive PhyNRdy 0x000a 2 14 Device-to-host register FISes sent due to a COMRESET 0x000b 2 0 CRC errors within host-to-device FIS 0x000d 2 0 Non-CRC errors within host-to-device FIS and this for sdc: SATA Phy Event Counters (GP Log 0x11) ID Size Value Description 0x0001 2 0 Command failed due to ICRC error 0x0002 2 0 R_ERR response for data FIS 0x0003 2 0 R_ERR response for device-to-host data FIS 0x0004 2 0 R_ERR response for host-to-device data FIS 0x0005 2 0 R_ERR response for non-data FIS 0x0006 2 0 R_ERR response for device-to-host non-data FIS 0x0007 2 0 R_ERR response for host-to-device non-data FIS 0x0009 2 3 Transition from drive PhyRdy to drive PhyNRdy 0x000a 2 2 Device-to-host register FISes sent due to a COMRESET 0x000b 2 0 CRC errors within host-to-device FIS 0x000d 2 0 Non-CRC errors within host-to-device FIS Tim. -- To unsubscribe from this list: send the line "unsubscribe linux-ide" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html