| Message ID | 20110610102403.GE15235@htj.dyndns.org |
|---|---|
| State | Not Applicable |
| Delegated to: | David Miller |
| Headers | show |
On 10/06/11 11:24, Tejun Heo wrote: > That's weird. Link is up but EH is detected to be up but EH didn't > probe it. Is the behavior reproducible? > I think-so, yes. I'll double-check. > Maybe FBS support doesn't work as advertised? Can you please try the > following patch? > > diff --git a/drivers/ata/libahci.c b/drivers/ata/libahci.c > index d38c40f..a2f4b68 100644 > --- a/drivers/ata/libahci.c > +++ b/drivers/ata/libahci.c > @@ -444,6 +444,7 @@ void ahci_save_initial_config(struct device *dev, > "controller can do FBS, turning on CAP_FBS\n"); > cap |= HOST_CAP_FBS; > } > + cap &= ~HOST_CAP_FBS; > > if (force_port_map && port_map != force_port_map) { > dev_printk(KERN_INFO, dev, "forcing port_map 0x%x -> 0x%x\n", > > OK, will do thanks - I assume this'll force command based switching, with it's associated crappy performance tho'... I've ordered an 88SE9128 card (Hightpoint RocketRaid 620) as well, so I'll be able to compare the two, as well as a sata_mv 88SX7042 as well. Cheers, Tim. -- To unsubscribe from this list: send the line "unsubscribe linux-ide" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On 10/06/11 17:43, Tim Small wrote: > > I've ordered an 88SE9128 card (Hightpoint RocketRaid 620) as well, so > I'll be able to compare the two, as well as a sata_mv 88SX7042 as well. > OK, so in fact it seems that I'd ordered a RocketRaid 620WDA - which has an 88SE9125 on it, not a 88SE9128 (as the 620 has). If I remember correctly (it was a couple of weeks ago now - just before I went on holiday) the 620WDA did actually work with the SiI 3726 PMP in FSC mode, when I was using the original HighPoint firmware which it shipped with, but it doesn't when I use the Marvell Firmware (I didn't want to try the Marvell firmware on the 620WDA, but the Marvell firmware update utility I had "upgraded" it - and now I can't put the Highpoint firmware back on it - partly because I don't have a copy of it anywhere). I was actually trying to upgrade the 88SE9123 firmware at the time - that turned out to be quite a lot more difficult than I was expecting: http://buttersideup.com/files/flashrom/lycom-pe115-flashrom-buspirate-2.jpg http://buttersideup.com/files/flashrom/at26f004-support.patch Marvell guys - can you tell whoever writes your DOS "mvf.exe" firmware updater for the 88SExxxx cards, that the update process fails to unprotect sectors on Atmel AT26F004 SPI flash chips - it also fails to check for protected sectors prior to attempting programming - so that you end up with part of one firmware version together with parts (which were in protected sectors) of whatever was there before. Also - actually automatically backing up the previous firmware would be nice, as well as some instructions for going back to the previous version in a README file (PLEASE PLEASE PLEASE), instead of leaving the users to scour the Internet for solutions to restoring non-working cards: http://www.station-drivers.com/forum/viewtopic.php?p=11162#p11163 ... oh, and whilst I think about it, when upgrading the flash on a machine with multiple adaptors - if the updater fails to successfully update one adaptor, maybe it should then STOP, rather than steaming on and breaking the rest of the cards in the same machine one after the other? Anyway, after all that I didn't actually get working PMP support with either card - at least not with that particular firmware image (which contains the version string: 1.0.0.1028 and is in "U3S6R0.zip" from http://www.station-drivers.com/page/marvell.htm ) the 88SE9125 seems to read successfully, but gives extremely slow read speeds - around 1 megabyte per second for simultaneous drive accesses in FBS mode, whereas the 88SE9123 gives the same behaviour as it did with the original firmware i.e. timeouts + resets during simultaneous reads in FBS mode. Is there a different firmware version which I should be trying with this card? Any chance of an actual changelog for the different firmware versions? Anyone have a 620WDA and wouldn't mind backing up the firmware from it for me? Is there a datasheet for the 88SE91xx chips around that I can get hold of - NDA or otherwise? Thanks, Tim. -- To unsubscribe from this list: send the line "unsubscribe linux-ide" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
A few more data points on this issue: I've tried the 88SE9123 and the 88SE9125 card in a Windows XP machine (a relatively slow PCI-e gen1 box), and have these results: 2x 2G Hitachi drives connected via a SiI 3726, and to a SiI 3132: works for simultaneous reads with hdparm (for Windows - http://hdparm-win32.dyndns.org/hdparm/ - simultaneous read done with "start /b hdparm -t /dev/sdb & hdparm -t /dev/sdc" at windows command prompt) - read speeds at 60M per second on both drives. Reads from a single drive at 115M per second. Reads from a single drive (direct to host, not via PMP) at 117M per second. 2x 2G Hitachi drives connected via a SiI 3726, and to a SiI 3132 (Debian 6.0 2.6.32 NCQ depth any) - works for simultaneous reads with hdparm - read speeds at 60M per second on both drives. Reads from a single drive at 122M per second. Reads from a single drive (direct to host, not via PMP) at 121M per second. 2x 2G Hitachi drives connected via a SiI 3726, and to the 88SE9123 card (Windows XP mv91xx.sys v1.1.0.6 14-Feb-2011 ) - works for simultaneous reads with hdparm - read speeds at 60M per second on both drives. Reads from a single drive at 117M per second. Reads from a single drive (direct to host, not via PMP) at 130M per second. 2x 2G Hitachi drives connected via a SiI 3726, and to the 88SE9123 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 30M per second on both drives. Reads from a single drive at 130M per second. Reads from a single drive (direct to host, not via PMP) at 130M per second. 2x 2G Hitachi drives connected via a SiI 3726, and to the 88SE9123 card ( Debian 6.0 2.6.32 NCQ depth 1 ) - works for simultaneous reads with hdparm - read speeds at 60M per second on both drives. Reads from a single drive at 130M per second. Reads from a single drive (direct to host, not via PMP) at 130M per second. 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). 2x 2G Hitachi drives connected via a SiI 3726, and to the 88SE9125 card ( Debian 6.0 2.6.32 NCQ 1 ) - works for simultaneous reads with hdparm - read speeds at 60M per second on both drives. Reads from a single drive at 130M per second. Reads from a single drive (direct to host, not via PMP) at 126M per second (consistantly 3M per second slower than via PMP!). Gotta dash, more testing later... Tim.
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@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
In the same machine as the previous test set, but with 2.6.38 (debian
squeeze backports kernel):
NCQ 1, two drives both connected to 3726 behind the **88SE9123**
(previous mail was for the 88SE9125):
# while true ; do sh -c "(hdparm -t /dev/sdb & hdparm -t /dev/sdc) 2>&1
| grep MB" ; done
Timing buffered disk reads: 190 MB in 3.02 seconds = 62.97 MB/sec
190 MB in 3.02 seconds = 62.99 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: 192 MB in 3.01 seconds = 63.87 MB/sec
194 MB in 3.01 seconds = 64.44 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.26 MB/sec
194 MB in 3.02 seconds = 64.23 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.14 MB/sec
194 MB in 3.03 seconds = 64.13 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.31 MB/sec
194 MB in 3.02 seconds = 64.18 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.31 MB/sec
194 MB in 3.02 seconds = 64.15 MB/sec
Timing buffered disk reads: 192 MB in 3.01 seconds = 63.73 MB/sec
196 MB in 3.02 seconds = 64.87 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.16 MB/sec
194 MB in 3.02 seconds = 64.27 MB/sec
Timing buffered disk reads: 192 MB in 3.01 seconds = 63.72 MB/sec
196 MB in 3.02 seconds = 64.83 MB/sec
Timing buffered disk reads: 194 MB in 3.01 seconds = 64.47 MB/sec
192 MB in 3.01 seconds = 63.79 MB/sec
... so it works, but is about 50% slower than the 88SE9125...
change NCQ depth to 31:
# while true ; do sh -c "(hdparm -t /dev/sdb & hdparm -t /dev/sdc) 2>&1
| grep MB" ; done
[after a considerable pause:]
Timing buffered disk reads: 382 MB in 3.01 seconds = 127.10 MB/sec
... i.e. one drive results only, the other read failed, with this in dmesg:
[ 2930.016043] ata7.00: failed to read SCR 1 (Emask=0x40)
[ 2930.020801] ata7.01: failed to read SCR 1 (Emask=0x40)
[ 2930.025429] ata7.02: failed to read SCR 1 (Emask=0x40)
[ 2930.029970] ata7.03: failed to read SCR 1 (Emask=0x40)
[ 2930.034447] ata7.04: failed to read SCR 1 (Emask=0x40)
[ 2930.038859] ata7.05: failed to read SCR 1 (Emask=0x40)
[ 2930.043218] ata7.15: exception Emask 0x4 SAct 0x0 SErr 0x0 action 0x6
frozen
[ 2930.047661] ata7.00: exception Emask 0x100 SAct 0xc SErr 0x0 action
0x6 frozen
[ 2930.052077] ata7.00: failed command: READ FPDMA QUEUED
[ 2930.056439] ata7.00: cmd 60/00:10:00:06:00/01:00:00:00:00/40 tag 2
ncq 131072 in
[ 2930.056443] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.065295] ata7.00: status: { DRDY }
[ 2930.069753] ata7.00: failed command: READ FPDMA QUEUED
[ 2930.074243] ata7.00: cmd 60/00:18:00:07:00/01:00:00:00:00/40 tag 3
ncq 131072 in
[ 2930.074247] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.083380] ata7.00: status: { DRDY }
[ 2930.087981] ata7.01: exception Emask 0x100 SAct 0x3 SErr 0x0 action
0x6 frozen
[ 2930.092672] ata7.01: failed command: READ FPDMA QUEUED
[ 2930.097279] ata7.01: cmd 60/00:00:00:06:00/01:00:00:00:00/40 tag 0
ncq 131072 in
[ 2930.097283] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.106463] ata7.01: status: { DRDY }
[ 2930.111040] ata7.01: failed command: READ FPDMA QUEUED
[ 2930.115630] ata7.01: cmd 60/00:08:00:07:00/01:00:00:00:00/40 tag 1
ncq 131072 in
[ 2930.115634] res 40/00:01:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.124786] ata7.01: status: { DRDY }
[ 2930.129349] ata7.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.133977] ata7.03: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.138537] ata7.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.143074] ata7.05: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.147538] ata7.15: hard resetting link
[ 2930.864034] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370)
[ 2930.868757] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2930.873236] ata7.15: PMP revalidation failed (errno=-19)
[ 2935.868025] ata7.15: hard resetting link
[ 2936.588038] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370)
[ 2936.592742] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2936.597296] ata7.15: PMP revalidation failed (errno=-19)
[ 2936.601803] ata7.15: limiting SATA link speed to 1.5 Gbps
[ 2941.592044] ata7.15: hard resetting link
[ 2942.312039] ata7.15: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 2942.316762] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2942.321236] ata7.15: PMP revalidation failed (errno=-19)
[ 2942.325672] ata7.15: failed to recover PMP after 5 tries, giving up
[ 2942.330101] ata7.15: Port Multiplier detaching
[ 2942.334489] ata7.00: disabled
[ 2942.338863] ata7.01: disabled
[ 2942.343145] ata7.00: disabled
[ 2947.316024] ata7: hard resetting link
[ 2948.036036] ata7: SATA link up 3.0 Gbps (SStatus 123 SControl 370)
[ 2948.040497] ata7.15: Port Multiplier 1.1, 0x1095:0x3726 r23, 6 ports,
feat 0x1/0x9
[ 2948.044701] ahci 0000:02:00.0: FBS is enabled.
[ 2948.049005] ata7.00: hard resetting link
[ 2948.368250] ata7.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ 2948.372472] ata7.01: hard resetting link
[ 2948.696248] ata7.01: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 2948.700471] ata7.02: hard resetting link
[ 2949.024255] ata7.02: SATA link down (SStatus 0 SControl 320)
[ 2949.028581] ata7.03: hard resetting link
[ 2949.352249] ata7.03: SATA link down (SStatus 0 SControl 320)
[ 2949.356582] ata7.04: hard resetting link
[ 2949.680248] ata7.04: SATA link down (SStatus 0 SControl 320)
[ 2949.684638] ata7.05: hard resetting link
[ 2950.008192] ata7.05: failed to write SCR 1 (Emask=0x1)
[ 2950.012618] ata7.05: SATA link down (SStatus 0 SControl 0)
[ 2950.018426] ata7.00: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 2950.022698] ata7.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth
31/32), AA
[ 2950.028551] ata7.00: configured for UDMA/133
[ 2950.034073] ata7.01: native sectors (2) is smaller than sectors
(3907029168)
[ 2950.038668] ata7.01: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 2950.043219] ata7.01: 3907029168 sectors, multi 0: LBA48 NCQ (depth
31/32), AA
[ 2950.049087] ata7.01: configured for UDMA/133
[ 2950.053758] ata7.01: device reported invalid CHS sector 0
[ 2950.058290] ata7.01: device reported invalid CHS sector 0
[ 2950.062735] ata7.00: device reported invalid CHS sector 0
[ 2950.067131] ata7.00: device reported invalid CHS sector 0
[ 2950.071451] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 2950.075844] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current]
[descriptor]
[ 2950.080228] Descriptor sense data with sense descriptors (in hex):
[ 2950.084616] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.089114] 00 00 00 00
[ 2950.093453] sd 6:1:0:0: [sdc] Add. Sense: No additional sense
information
[ 2950.097839] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 06 00 00 01
00 00
[ 2950.102283] end_request: I/O error, dev sdc, sector 1536
[ 2950.106652] quiet_error: 45 callbacks suppressed
[ 2950.110957] Buffer I/O error on device sdc, logical block 192
[ 2950.115306] Buffer I/O error on device sdc, logical block 193
[ 2950.119578] Buffer I/O error on device sdc, logical block 194
[ 2950.123816] Buffer I/O error on device sdc, logical block 195
[ 2950.127958] Buffer I/O error on device sdc, logical block 196
[ 2950.132036] Buffer I/O error on device sdc, logical block 197
[ 2950.136119] Buffer I/O error on device sdc, logical block 198
[ 2950.140190] Buffer I/O error on device sdc, logical block 199
[ 2950.144269] Buffer I/O error on device sdc, logical block 200
[ 2950.148281] Buffer I/O error on device sdc, logical block 201
[ 2950.152265] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 2950.156275] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current]
[descriptor]
[ 2950.160289] Descriptor sense data with sense descriptors (in hex):
[ 2950.164318] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.168471] 00 00 00 00
[ 2950.172471] sd 6:1:0:0: [sdc] Add. Sense: No additional sense
information
[ 2950.176525] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 07 00 00 01
00 00
[ 2950.180659] end_request: I/O error, dev sdc, sector 1792
[ 2950.184743] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 2950.188856] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current]
[descriptor]
[ 2950.192976] Descriptor sense data with sense descriptors (in hex):
[ 2950.197094] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.201337] 00 00 00 00
[ 2950.205439] sd 6:0:0:0: [sdb] Add. Sense: No additional sense
information
[ 2950.209626] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 06 00 00 01
00 00
[ 2950.213939] end_request: I/O error, dev sdb, sector 1536
[ 2950.218252] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 2950.222627] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current]
[descriptor]
[ 2950.227010] Descriptor sense data with sense descriptors (in hex):
[ 2950.231370] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.235813] 00 00 00 00
[ 2950.240143] sd 6:0:0:0: [sdb] Add. Sense: No additional sense
information
[ 2950.244528] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 07 00 00 01
00 00
[ 2950.248975] end_request: I/O error, dev sdb, sector 1792
[ 2950.253351] ata7: EH complete
[ 2950.257986] ata7.00: detaching (SCSI 6:0:0:0)
[ 2950.260412] sd 6:1:0:0: rejecting I/O to offline device
[ 2950.262676] sd 6:0:0:0: rejecting I/O to offline device
[ 2950.272236] sd 6:0:0:0: [sdb] Synchronizing SCSI cache
[ 2950.274778] sd 6:0:0:0: [sdb] Stopping disk
[ 2950.284568] end_request: I/O error, dev sdb, sector 0
[ 2950.287099] sd 6:1:0:0: rejecting I/O to offline device
[ 2950.288321] end_request: I/O error, dev sdc, sector 0
[ 2950.291531] end_request: I/O error, dev sdb, sector 0
[ 2950.293912] sd 6:1:0:0: rejecting I/O to offline device
[ 2950.296077] end_request: I/O error, dev sdc, sector 0
[ 2950.868137] ata7.01: detaching (SCSI 6:1:0:0)
[ 2950.879987] sd 6:1:0:0: [sdc] Synchronizing SCSI cache
[ 2950.884351] sd 6:1:0:0: [sdc] Stopping disk
[ 2951.490748] scsi 6:0:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 2951.497341] sd 6:0:0:0: [sdb] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 2951.501834] sd 6:0:0:0: [sdb] Write Protect is off
[ 2951.506067] sd 6:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[ 2951.506855] scsi 6:1:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 2951.518252] sd 6:0:0:0: [sdb] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 2951.523911] sd 6:1:0:0: [sdc] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 2951.530008] sd 6:1:0:0: [sdc] Write Protect is off
[ 2951.532522] sd 6:1:0:0: [sdc] Mode Sense: 00 3a 00 00
[ 2951.533349] sd 6:1:0:0: [sdc] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 2953.444386] sdc: sdc1
[ 2953.450667] sd 6:1:0:0: [sdc] Attached SCSI disk
[ 2954.301886] sdb: sdb1
[ 2954.311753] sd 6:0:0:0: [sdb] Attached SCSI disk
[ 2994.016046] ata7.00: failed to read SCR 1 (Emask=0x40)
[ 2994.020684] ata7.01: failed to read SCR 1 (Emask=0x40)
[ 2994.025282] ata7.02: failed to read SCR 1 (Emask=0x40)
[ 2994.029859] ata7.03: failed to read SCR 1 (Emask=0x40)
[ 2994.034443] ata7.04: failed to read SCR 1 (Emask=0x40)
[ 2994.039024] ata7.05: failed to read SCR 1 (Emask=0x40)
[ 2994.043613] ata7.15: exception Emask 0x4 SAct 0x0 SErr 0x400000
action 0x6 frozen
[ 2994.048221] ata7.15: SError: { Handshk }
[ 2994.052790] ata7.00: exception Emask 0x100 SAct 0xa SErr 0x0 action
0x6 frozen
[ 2994.057393] ata7.00: failed command: READ FPDMA QUEUED
[ 2994.061957] ata7.00: cmd 60/00:08:00:18:00/01:00:00:00:00/40 tag 1
ncq 131072 in
[ 2994.061961] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.071179] ata7.00: status: { DRDY }
[ 2994.075747] ata7.00: failed command: READ FPDMA QUEUED
[ 2994.080311] ata7.00: cmd 60/00:18:00:19:00/01:00:00:00:00/40 tag 3
ncq 131072 in
[ 2994.080314] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.089460] ata7.00: status: { DRDY }
[ 2994.093974] ata7.01: exception Emask 0x100 SAct 0x5 SErr 0x0 action
0x6 frozen
[ 2994.098544] ata7.01: failed command: READ FPDMA QUEUED
[ 2994.103096] ata7.01: cmd 60/00:00:00:04:00/01:00:00:00:00/40 tag 0
ncq 131072 in
[ 2994.103099] res 40/00:01:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.112254] ata7.01: status: { DRDY }
[ 2994.116770] ata7.01: failed command: READ FPDMA QUEUED
[ 2994.121280] ata7.01: cmd 60/00:10:00:05:00/01:00:00:00:00/40 tag 2
ncq 131072 in
[ 2994.121283] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.130329] ata7.01: status: { DRDY }
[ 2994.134794] ata7.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.139343] ata7.03: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.143815] ata7.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.148233] ata7.05: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.152588] ata7.15: hard resetting link
[ 2994.872040] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370)
[ 2994.876666] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2994.881056] ata7.15: PMP revalidation failed (errno=-19)
[ 2999.876031] ata7.15: hard resetting link
[ 3000.596037] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370)
[ 3000.600759] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 3000.605307] ata7.15: PMP revalidation failed (errno=-19)
[ 3000.609803] ata7.15: limiting SATA link speed to 1.5 Gbps
[ 3005.600038] ata7.15: hard resetting link
[ 3006.320038] ata7.15: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 3006.324835] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 3006.329398] ata7.15: PMP revalidation failed (errno=-19)
[ 3006.333932] ata7.15: failed to recover PMP after 5 tries, giving up
[ 3006.338486] ata7.15: Port Multiplier detaching
[ 3006.343045] ata7.00: disabled
[ 3006.347531] ata7.01: disabled
[ 3006.351918] ata7.00: disabled
[ 3011.324021] ata7: hard resetting link
[ 3012.044038] ata7: SATA link up 3.0 Gbps (SStatus 123 SControl 370)
[ 3012.048607] ata7.15: Port Multiplier 1.1, 0x1095:0x3726 r23, 6 ports,
feat 0x1/0x9
[ 3012.052909] ahci 0000:02:00.0: FBS is enabled.
[ 3012.057467] ata7.00: hard resetting link
[ 3012.376255] ata7.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ 3012.380560] ata7.01: hard resetting link
[ 3012.704248] ata7.01: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 3012.708580] ata7.02: hard resetting link
[ 3013.032247] ata7.02: SATA link down (SStatus 0 SControl 320)
[ 3013.036615] ata7.03: hard resetting link
[ 3013.360248] ata7.03: SATA link down (SStatus 0 SControl 320)
[ 3013.364635] ata7.04: hard resetting link
[ 3013.688246] ata7.04: SATA link down (SStatus 0 SControl 320)
[ 3013.692689] ata7.05: hard resetting link
[ 3014.016194] ata7.05: failed to write SCR 1 (Emask=0x1)
[ 3014.020635] ata7.05: SATA link down (SStatus 0 SControl 0)
[ 3014.026285] ata7.00: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 3014.030646] ata7.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth
31/32), AA
[ 3014.036430] ata7.00: configured for UDMA/133
[ 3014.042023] ata7.01: native sectors (2) is smaller than sectors
(3907029168)
[ 3014.046718] ata7.01: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 3014.051279] ata7.01: 3907029168 sectors, multi 0: LBA48 NCQ (depth
31/32), AA
[ 3014.057159] ata7.01: configured for UDMA/133
[ 3014.059537] ata7.01: device reported invalid CHS sector 0
[ 3014.061890] ata7.00: device reported invalid CHS sector 0
[ 3014.064203] ata7.01: device reported invalid CHS sector 0
[ 3014.066474] ata7.00: device reported invalid CHS sector 0
[ 3014.068733] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 3014.071007] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current]
[descriptor]
[ 3014.073291] Descriptor sense data with sense descriptors (in hex):
[ 3014.075562] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.077904] 00 00 00 00
[ 3014.080183] sd 6:1:0:0: [sdc] Add. Sense: No additional sense
information
[ 3014.082476] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 04 00 00 01
00 00
[ 3014.084797] end_request: I/O error, dev sdc, sector 1024
[ 3014.087077] quiet_error: 118 callbacks suppressed
[ 3014.089320] Buffer I/O error on device sdc, logical block 128
[ 3014.091593] Buffer I/O error on device sdc, logical block 129
[ 3014.093817] Buffer I/O error on device sdc, logical block 130
[ 3014.096015] Buffer I/O error on device sdc, logical block 131
[ 3014.098167] Buffer I/O error on device sdc, logical block 132
[ 3014.100286] Buffer I/O error on device sdc, logical block 133
[ 3014.102402] Buffer I/O error on device sdc, logical block 134
[ 3014.104521] Buffer I/O error on device sdc, logical block 135
[ 3014.106638] Buffer I/O error on device sdc, logical block 136
[ 3014.108721] Buffer I/O error on device sdc, logical block 137
[ 3014.110792] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 3014.112877] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current]
[descriptor]
[ 3014.114966] Descriptor sense data with sense descriptors (in hex):
[ 3014.117053] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.119211] 00 00 00 00
[ 3014.121313] sd 6:0:0:0: [sdb] Add. Sense: No additional sense
information
[ 3014.123421] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 18 00 00 01
00 00
[ 3014.125605] end_request: I/O error, dev sdb, sector 6144
[ 3014.127754] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 3014.129913] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current]
[descriptor]
[ 3014.132067] Descriptor sense data with sense descriptors (in hex):
[ 3014.134199] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.136423] 00 00 00 00
[ 3014.138587] sd 6:1:0:0: [sdc] Add. Sense: No additional sense
information
[ 3014.140791] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 05 00 00 01
00 00
[ 3014.143051] end_request: I/O error, dev sdc, sector 1280
[ 3014.145323] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE
[ 3014.147615] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current]
[descriptor]
[ 3014.149897] Descriptor sense data with sense descriptors (in hex):
[ 3014.152156] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.154478] 00 00 00 00
[ 3014.156758] sd 6:0:0:0: [sdb] Add. Sense: No additional sense
information
[ 3014.159056] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 19 00 00 01
00 00
[ 3014.161406] end_request: I/O error, dev sdb, sector 6400
[ 3014.163703] ata7: EH complete
[ 3014.165979] ata7.00: detaching (SCSI 6:0:0:0)
[ 3014.168308] sd 6:0:0:0: rejecting I/O to offline device
[ 3014.177610] sd 6:0:0:0: [sdb] Synchronizing SCSI cache
[ 3014.179969] sd 6:0:0:0: [sdb] Stopping disk
[ 3014.791747] ata7.01: detaching (SCSI 6:1:0:0)
[ 3014.799621] sd 6:1:0:0: [sdc] Synchronizing SCSI cache
[ 3014.804160] sd 6:1:0:0: [sdc] Stopping disk
[ 3015.419701] scsi 6:0:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 3015.425355] sd 6:0:0:0: [sdb] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 3015.429980] sd 6:0:0:0: [sdb] Write Protect is off
[ 3015.434322] sd 6:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[ 3015.435019] scsi 6:1:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 3015.440304] sd 6:0:0:0: [sdb] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 3015.445835] sd 6:1:0:0: [sdc] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 3015.450897] sd 6:1:0:0: [sdc] Write Protect is off
[ 3015.455341] sd 6:1:0:0: [sdc] Mode Sense: 00 3a 00 00
[ 3015.456615] sd 6:1:0:0: [sdc] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 3017.371727] sdc: sdc1
[ 3017.377835] sd 6:1:0:0: [sdc] Attached SCSI disk
[ 3018.219239] sdb: sdb1
[ 3018.225421] sd 6:0:0:0: [sdb] Attached SCSI disk
... and the drives have this smartctl output:
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 56 Transition from drive PhyRdy to drive PhyNRdy
0x000a 2 35 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
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 9 Transition from drive PhyRdy to drive PhyNRdy
0x000a 2 5 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
Sorry - I accidentally sent this from the wrong email address, which I think kept it from reaching the list. 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@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Tim,
The 9125 is a simple controller without a internal processor. The 9123 contains an internal processor to enhance RAID 0/1 operations. If you are testing in a JBOD configuration you will not take advantage of the 9123 internal processor. The internal processor can result in lower performance than the 9125. However if you configure the drives in a RAID configuration using the 9123 RAID utility you should see better performance than with 9125.
-----Original Message-----
From: Tim Small [mailto:tim@seoss.co.uk]
Sent: Thursday, July 07, 2011 1:39 PM
To: Tejun Heo; Hubert Bailey; Larry Li; linux-ide@vger.kernel.org
Subject: Re: SiI 3726 pmp doesn't work with 2.6.38 and Marvell 88SE9123 AHCI controller
In the same machine as the previous test set, but with 2.6.38 (debian squeeze backports kernel):
NCQ 1, two drives both connected to 3726 behind the **88SE9123** (previous mail was for the 88SE9125):
# while true ; do sh -c "(hdparm -t /dev/sdb & hdparm -t /dev/sdc) 2>&1
| grep MB" ; done
Timing buffered disk reads: 190 MB in 3.02 seconds = 62.97 MB/sec 190 MB in 3.02 seconds = 62.99 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: 192 MB in 3.01 seconds = 63.87 MB/sec
194 MB in 3.01 seconds = 64.44 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.26 MB/sec
194 MB in 3.02 seconds = 64.23 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.14 MB/sec
194 MB in 3.03 seconds = 64.13 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.31 MB/sec
194 MB in 3.02 seconds = 64.18 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.31 MB/sec
194 MB in 3.02 seconds = 64.15 MB/sec
Timing buffered disk reads: 192 MB in 3.01 seconds = 63.73 MB/sec
196 MB in 3.02 seconds = 64.87 MB/sec
Timing buffered disk reads: 194 MB in 3.02 seconds = 64.16 MB/sec
194 MB in 3.02 seconds = 64.27 MB/sec
Timing buffered disk reads: 192 MB in 3.01 seconds = 63.72 MB/sec
196 MB in 3.02 seconds = 64.83 MB/sec
Timing buffered disk reads: 194 MB in 3.01 seconds = 64.47 MB/sec
192 MB in 3.01 seconds = 63.79 MB/sec
... so it works, but is about 50% slower than the 88SE9125...
change NCQ depth to 31:
# while true ; do sh -c "(hdparm -t /dev/sdb & hdparm -t /dev/sdc) 2>&1
| grep MB" ; done
[after a considerable pause:]
Timing buffered disk reads: 382 MB in 3.01 seconds = 127.10 MB/sec
... i.e. one drive results only, the other read failed, with this in dmesg:
[ 2930.016043] ata7.00: failed to read SCR 1 (Emask=0x40) [ 2930.020801] ata7.01: failed to read SCR 1 (Emask=0x40) [ 2930.025429] ata7.02: failed to read SCR 1 (Emask=0x40) [ 2930.029970] ata7.03: failed to read SCR 1 (Emask=0x40) [ 2930.034447] ata7.04: failed to read SCR 1 (Emask=0x40) [ 2930.038859] ata7.05: failed to read SCR 1 (Emask=0x40) [ 2930.043218] ata7.15: exception Emask 0x4 SAct 0x0 SErr 0x0 action 0x6 frozen [ 2930.047661] ata7.00: exception Emask 0x100 SAct 0xc SErr 0x0 action
0x6 frozen
[ 2930.052077] ata7.00: failed command: READ FPDMA QUEUED [ 2930.056439] ata7.00: cmd 60/00:10:00:06:00/01:00:00:00:00/40 tag 2 ncq 131072 in
[ 2930.056443] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.065295] ata7.00: status: { DRDY } [ 2930.069753] ata7.00: failed command: READ FPDMA QUEUED [ 2930.074243] ata7.00: cmd 60/00:18:00:07:00/01:00:00:00:00/40 tag 3 ncq 131072 in
[ 2930.074247] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.083380] ata7.00: status: { DRDY } [ 2930.087981] ata7.01: exception Emask 0x100 SAct 0x3 SErr 0x0 action
0x6 frozen
[ 2930.092672] ata7.01: failed command: READ FPDMA QUEUED [ 2930.097279] ata7.01: cmd 60/00:00:00:06:00/01:00:00:00:00/40 tag 0 ncq 131072 in
[ 2930.097283] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.106463] ata7.01: status: { DRDY } [ 2930.111040] ata7.01: failed command: READ FPDMA QUEUED [ 2930.115630] ata7.01: cmd 60/00:08:00:07:00/01:00:00:00:00/40 tag 1 ncq 131072 in
[ 2930.115634] res 40/00:01:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2930.124786] ata7.01: status: { DRDY } [ 2930.129349] ata7.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.133977] ata7.03: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.138537] ata7.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.143074] ata7.05: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2930.147538] ata7.15: hard resetting link [ 2930.864034] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370) [ 2930.868757] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2930.873236] ata7.15: PMP revalidation failed (errno=-19) [ 2935.868025] ata7.15: hard resetting link [ 2936.588038] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370) [ 2936.592742] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2936.597296] ata7.15: PMP revalidation failed (errno=-19) [ 2936.601803] ata7.15: limiting SATA link speed to 1.5 Gbps [ 2941.592044] ata7.15: hard resetting link [ 2942.312039] ata7.15: SATA link up 1.5 Gbps (SStatus 113 SControl 310) [ 2942.316762] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2942.321236] ata7.15: PMP revalidation failed (errno=-19) [ 2942.325672] ata7.15: failed to recover PMP after 5 tries, giving up [ 2942.330101] ata7.15: Port Multiplier detaching [ 2942.334489] ata7.00: disabled [ 2942.338863] ata7.01: disabled [ 2942.343145] ata7.00: disabled [ 2947.316024] ata7: hard resetting link [ 2948.036036] ata7: SATA link up 3.0 Gbps (SStatus 123 SControl 370) [ 2948.040497] ata7.15: Port Multiplier 1.1, 0x1095:0x3726 r23, 6 ports, feat 0x1/0x9 [ 2948.044701] ahci 0000:02:00.0: FBS is enabled.
[ 2948.049005] ata7.00: hard resetting link [ 2948.368250] ata7.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320) [ 2948.372472] ata7.01: hard resetting link [ 2948.696248] ata7.01: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 2948.700471] ata7.02: hard resetting link [ 2949.024255] ata7.02: SATA link down (SStatus 0 SControl 320) [ 2949.028581] ata7.03: hard resetting link [ 2949.352249] ata7.03: SATA link down (SStatus 0 SControl 320) [ 2949.356582] ata7.04: hard resetting link [ 2949.680248] ata7.04: SATA link down (SStatus 0 SControl 320) [ 2949.684638] ata7.05: hard resetting link [ 2950.008192] ata7.05: failed to write SCR 1 (Emask=0x1) [ 2950.012618] ata7.05: SATA link down (SStatus 0 SControl 0) [ 2950.018426] ata7.00: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 2950.022698] ata7.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32), AA [ 2950.028551] ata7.00: configured for UDMA/133 [ 2950.034073] ata7.01: native sectors (2) is smaller than sectors
(3907029168)
[ 2950.038668] ata7.01: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 2950.043219] ata7.01: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32), AA [ 2950.049087] ata7.01: configured for UDMA/133 [ 2950.053758] ata7.01: device reported invalid CHS sector 0 [ 2950.058290] ata7.01: device reported invalid CHS sector 0 [ 2950.062735] ata7.00: device reported invalid CHS sector 0 [ 2950.067131] ata7.00: device reported invalid CHS sector 0 [ 2950.071451] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 2950.075844] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current] [descriptor] [ 2950.080228] Descriptor sense data with sense descriptors (in hex):
[ 2950.084616] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.089114] 00 00 00 00
[ 2950.093453] sd 6:1:0:0: [sdc] Add. Sense: No additional sense information [ 2950.097839] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 06 00 00 01 00 00 [ 2950.102283] end_request: I/O error, dev sdc, sector 1536 [ 2950.106652] quiet_error: 45 callbacks suppressed [ 2950.110957] Buffer I/O error on device sdc, logical block 192 [ 2950.115306] Buffer I/O error on device sdc, logical block 193 [ 2950.119578] Buffer I/O error on device sdc, logical block 194 [ 2950.123816] Buffer I/O error on device sdc, logical block 195 [ 2950.127958] Buffer I/O error on device sdc, logical block 196 [ 2950.132036] Buffer I/O error on device sdc, logical block 197 [ 2950.136119] Buffer I/O error on device sdc, logical block 198 [ 2950.140190] Buffer I/O error on device sdc, logical block 199 [ 2950.144269] Buffer I/O error on device sdc, logical block 200 [ 2950.148281] Buffer I/O error on device sdc, logical block 201 [ 2950.152265] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 2950.156275] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current] [descriptor] [ 2950.160289] Descriptor sense data with sense descriptors (in hex):
[ 2950.164318] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.168471] 00 00 00 00
[ 2950.172471] sd 6:1:0:0: [sdc] Add. Sense: No additional sense information [ 2950.176525] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 07 00 00 01 00 00 [ 2950.180659] end_request: I/O error, dev sdc, sector 1792 [ 2950.184743] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 2950.188856] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor] [ 2950.192976] Descriptor sense data with sense descriptors (in hex):
[ 2950.197094] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.201337] 00 00 00 00
[ 2950.205439] sd 6:0:0:0: [sdb] Add. Sense: No additional sense information [ 2950.209626] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 06 00 00 01 00 00 [ 2950.213939] end_request: I/O error, dev sdb, sector 1536 [ 2950.218252] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 2950.222627] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor] [ 2950.227010] Descriptor sense data with sense descriptors (in hex):
[ 2950.231370] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 2950.235813] 00 00 00 00
[ 2950.240143] sd 6:0:0:0: [sdb] Add. Sense: No additional sense information [ 2950.244528] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 07 00 00 01 00 00 [ 2950.248975] end_request: I/O error, dev sdb, sector 1792 [ 2950.253351] ata7: EH complete [ 2950.257986] ata7.00: detaching (SCSI 6:0:0:0) [ 2950.260412] sd 6:1:0:0: rejecting I/O to offline device [ 2950.262676] sd 6:0:0:0: rejecting I/O to offline device [ 2950.272236] sd 6:0:0:0: [sdb] Synchronizing SCSI cache [ 2950.274778] sd 6:0:0:0: [sdb] Stopping disk [ 2950.284568] end_request: I/O error, dev sdb, sector 0 [ 2950.287099] sd 6:1:0:0: rejecting I/O to offline device [ 2950.288321] end_request: I/O error, dev sdc, sector 0 [ 2950.291531] end_request: I/O error, dev sdb, sector 0 [ 2950.293912] sd 6:1:0:0: rejecting I/O to offline device [ 2950.296077] end_request: I/O error, dev sdc, sector 0 [ 2950.868137] ata7.01: detaching (SCSI 6:1:0:0) [ 2950.879987] sd 6:1:0:0: [sdc] Synchronizing SCSI cache [ 2950.884351] sd 6:1:0:0: [sdc] Stopping disk
[ 2951.490748] scsi 6:0:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 2951.497341] sd 6:0:0:0: [sdb] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 2951.501834] sd 6:0:0:0: [sdb] Write Protect is off [ 2951.506067] sd 6:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[ 2951.506855] scsi 6:1:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 2951.518252] sd 6:0:0:0: [sdb] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 2951.523911] sd 6:1:0:0: [sdc] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 2951.530008] sd 6:1:0:0: [sdc] Write Protect is off [ 2951.532522] sd 6:1:0:0: [sdc] Mode Sense: 00 3a 00 00 [ 2951.533349] sd 6:1:0:0: [sdc] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 2953.444386] sdc: sdc1
[ 2953.450667] sd 6:1:0:0: [sdc] Attached SCSI disk [ 2954.301886] sdb: sdb1 [ 2954.311753] sd 6:0:0:0: [sdb] Attached SCSI disk [ 2994.016046] ata7.00: failed to read SCR 1 (Emask=0x40) [ 2994.020684] ata7.01: failed to read SCR 1 (Emask=0x40) [ 2994.025282] ata7.02: failed to read SCR 1 (Emask=0x40) [ 2994.029859] ata7.03: failed to read SCR 1 (Emask=0x40) [ 2994.034443] ata7.04: failed to read SCR 1 (Emask=0x40) [ 2994.039024] ata7.05: failed to read SCR 1 (Emask=0x40) [ 2994.043613] ata7.15: exception Emask 0x4 SAct 0x0 SErr 0x400000 action 0x6 frozen [ 2994.048221] ata7.15: SError: { Handshk } [ 2994.052790] ata7.00: exception Emask 0x100 SAct 0xa SErr 0x0 action
0x6 frozen
[ 2994.057393] ata7.00: failed command: READ FPDMA QUEUED [ 2994.061957] ata7.00: cmd 60/00:08:00:18:00/01:00:00:00:00/40 tag 1 ncq 131072 in
[ 2994.061961] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.071179] ata7.00: status: { DRDY } [ 2994.075747] ata7.00: failed command: READ FPDMA QUEUED [ 2994.080311] ata7.00: cmd 60/00:18:00:19:00/01:00:00:00:00/40 tag 3 ncq 131072 in
[ 2994.080314] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.089460] ata7.00: status: { DRDY } [ 2994.093974] ata7.01: exception Emask 0x100 SAct 0x5 SErr 0x0 action
0x6 frozen
[ 2994.098544] ata7.01: failed command: READ FPDMA QUEUED [ 2994.103096] ata7.01: cmd 60/00:00:00:04:00/01:00:00:00:00/40 tag 0 ncq 131072 in
[ 2994.103099] res 40/00:01:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.112254] ata7.01: status: { DRDY } [ 2994.116770] ata7.01: failed command: READ FPDMA QUEUED [ 2994.121280] ata7.01: cmd 60/00:10:00:05:00/01:00:00:00:00/40 tag 2 ncq 131072 in
[ 2994.121283] res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[ 2994.130329] ata7.01: status: { DRDY } [ 2994.134794] ata7.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.139343] ata7.03: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.143815] ata7.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.148233] ata7.05: exception Emask 0x100 SAct 0x0 SErr 0x0 action
0x6 frozen
[ 2994.152588] ata7.15: hard resetting link [ 2994.872040] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370) [ 2994.876666] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 2994.881056] ata7.15: PMP revalidation failed (errno=-19) [ 2999.876031] ata7.15: hard resetting link [ 3000.596037] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 370) [ 3000.600759] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 3000.605307] ata7.15: PMP revalidation failed (errno=-19) [ 3000.609803] ata7.15: limiting SATA link speed to 1.5 Gbps [ 3005.600038] ata7.15: hard resetting link [ 3006.320038] ata7.15: SATA link up 1.5 Gbps (SStatus 113 SControl 310) [ 3006.324835] ata7.15: Port Multiplier vendor mismatch '0x1095' != '0x0'
[ 3006.329398] ata7.15: PMP revalidation failed (errno=-19) [ 3006.333932] ata7.15: failed to recover PMP after 5 tries, giving up [ 3006.338486] ata7.15: Port Multiplier detaching [ 3006.343045] ata7.00: disabled [ 3006.347531] ata7.01: disabled [ 3006.351918] ata7.00: disabled [ 3011.324021] ata7: hard resetting link [ 3012.044038] ata7: SATA link up 3.0 Gbps (SStatus 123 SControl 370) [ 3012.048607] ata7.15: Port Multiplier 1.1, 0x1095:0x3726 r23, 6 ports, feat 0x1/0x9 [ 3012.052909] ahci 0000:02:00.0: FBS is enabled.
[ 3012.057467] ata7.00: hard resetting link [ 3012.376255] ata7.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320) [ 3012.380560] ata7.01: hard resetting link [ 3012.704248] ata7.01: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 3012.708580] ata7.02: hard resetting link [ 3013.032247] ata7.02: SATA link down (SStatus 0 SControl 320) [ 3013.036615] ata7.03: hard resetting link [ 3013.360248] ata7.03: SATA link down (SStatus 0 SControl 320) [ 3013.364635] ata7.04: hard resetting link [ 3013.688246] ata7.04: SATA link down (SStatus 0 SControl 320) [ 3013.692689] ata7.05: hard resetting link [ 3014.016194] ata7.05: failed to write SCR 1 (Emask=0x1) [ 3014.020635] ata7.05: SATA link down (SStatus 0 SControl 0) [ 3014.026285] ata7.00: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 3014.030646] ata7.00: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32), AA [ 3014.036430] ata7.00: configured for UDMA/133 [ 3014.042023] ata7.01: native sectors (2) is smaller than sectors
(3907029168)
[ 3014.046718] ata7.01: ATA-8: Hitachi HDS5C3020ALA632, ML6OA580, max
UDMA/133
[ 3014.051279] ata7.01: 3907029168 sectors, multi 0: LBA48 NCQ (depth 31/32), AA [ 3014.057159] ata7.01: configured for UDMA/133 [ 3014.059537] ata7.01: device reported invalid CHS sector 0 [ 3014.061890] ata7.00: device reported invalid CHS sector 0 [ 3014.064203] ata7.01: device reported invalid CHS sector 0 [ 3014.066474] ata7.00: device reported invalid CHS sector 0 [ 3014.068733] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 3014.071007] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current] [descriptor] [ 3014.073291] Descriptor sense data with sense descriptors (in hex):
[ 3014.075562] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.077904] 00 00 00 00
[ 3014.080183] sd 6:1:0:0: [sdc] Add. Sense: No additional sense information [ 3014.082476] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 04 00 00 01 00 00 [ 3014.084797] end_request: I/O error, dev sdc, sector 1024 [ 3014.087077] quiet_error: 118 callbacks suppressed [ 3014.089320] Buffer I/O error on device sdc, logical block 128 [ 3014.091593] Buffer I/O error on device sdc, logical block 129 [ 3014.093817] Buffer I/O error on device sdc, logical block 130 [ 3014.096015] Buffer I/O error on device sdc, logical block 131 [ 3014.098167] Buffer I/O error on device sdc, logical block 132 [ 3014.100286] Buffer I/O error on device sdc, logical block 133 [ 3014.102402] Buffer I/O error on device sdc, logical block 134 [ 3014.104521] Buffer I/O error on device sdc, logical block 135 [ 3014.106638] Buffer I/O error on device sdc, logical block 136 [ 3014.108721] Buffer I/O error on device sdc, logical block 137 [ 3014.110792] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 3014.112877] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor] [ 3014.114966] Descriptor sense data with sense descriptors (in hex):
[ 3014.117053] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.119211] 00 00 00 00
[ 3014.121313] sd 6:0:0:0: [sdb] Add. Sense: No additional sense information [ 3014.123421] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 18 00 00 01 00 00 [ 3014.125605] end_request: I/O error, dev sdb, sector 6144 [ 3014.127754] sd 6:1:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 3014.129913] sd 6:1:0:0: [sdc] Sense Key : Aborted Command [current] [descriptor] [ 3014.132067] Descriptor sense data with sense descriptors (in hex):
[ 3014.134199] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.136423] 00 00 00 00
[ 3014.138587] sd 6:1:0:0: [sdc] Add. Sense: No additional sense information [ 3014.140791] sd 6:1:0:0: [sdc] CDB: Read(10): 28 00 00 00 05 00 00 01 00 00 [ 3014.143051] end_request: I/O error, dev sdc, sector 1280 [ 3014.145323] sd 6:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 3014.147615] sd 6:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor] [ 3014.149897] Descriptor sense data with sense descriptors (in hex):
[ 3014.152156] 72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
[ 3014.154478] 00 00 00 00
[ 3014.156758] sd 6:0:0:0: [sdb] Add. Sense: No additional sense information [ 3014.159056] sd 6:0:0:0: [sdb] CDB: Read(10): 28 00 00 00 19 00 00 01 00 00 [ 3014.161406] end_request: I/O error, dev sdb, sector 6400 [ 3014.163703] ata7: EH complete [ 3014.165979] ata7.00: detaching (SCSI 6:0:0:0) [ 3014.168308] sd 6:0:0:0: rejecting I/O to offline device [ 3014.177610] sd 6:0:0:0: [sdb] Synchronizing SCSI cache [ 3014.179969] sd 6:0:0:0: [sdb] Stopping disk [ 3014.791747] ata7.01: detaching (SCSI 6:1:0:0) [ 3014.799621] sd 6:1:0:0: [sdc] Synchronizing SCSI cache [ 3014.804160] sd 6:1:0:0: [sdc] Stopping disk
[ 3015.419701] scsi 6:0:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 3015.425355] sd 6:0:0:0: [sdb] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 3015.429980] sd 6:0:0:0: [sdb] Write Protect is off [ 3015.434322] sd 6:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[ 3015.435019] scsi 6:1:0:0: Direct-Access ATA Hitachi HDS5C302
ML6O PQ: 0 ANSI: 5
[ 3015.440304] sd 6:0:0:0: [sdb] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 3015.445835] sd 6:1:0:0: [sdc] 3907029168 512-byte logical blocks:
(2.00 TB/1.81 TiB)
[ 3015.450897] sd 6:1:0:0: [sdc] Write Protect is off [ 3015.455341] sd 6:1:0:0: [sdc] Mode Sense: 00 3a 00 00 [ 3015.456615] sd 6:1:0:0: [sdc] Write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[ 3017.371727] sdc: sdc1
[ 3017.377835] sd 6:1:0:0: [sdc] Attached SCSI disk [ 3018.219239] sdb: sdb1 [ 3018.225421] sd 6:0:0:0: [sdb] Attached SCSI disk
... and the drives have this smartctl output:
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 56 Transition from drive PhyRdy to drive PhyNRdy
0x000a 2 35 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
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 9 Transition from drive PhyRdy to drive PhyNRdy
0x000a 2 5 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
--
South East Open Source Solutions Limited Registered in England and Wales with company number 06134732.
Registered Office: 2 Powell Gardens, Redhill, Surrey, RH1 1TQ VAT number: 900 6633 53 http://seoss.co.uk/ +44-(0)1273-808309
-----
No virus found in this message.
Checked by AVG - www.avg.com
Version: 10.0.1388 / Virus Database: 1516/3750 - Release Date: 07/07/11
--
To unsubscribe from this list: send the line "unsubscribe linux-ide" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
On 08/07/11 05:42, Hubert Bailey wrote: > Tim, > > The 9125 is a simple controller without a internal processor. The 9123 contains an internal processor to enhance RAID 0/1 operations. If you are testing in a JBOD configuration you will not take advantage of the 9123 internal processor. OK, that's fine. I have a nice fast CPU in the system which runs the Linux md code (which I can debug if necessary) with very high throughput, and it even works across controller cards. A JBOD is what I want. > The internal processor can result in lower performance than the 9125. It shouldn't result it complete read failures though, should it? That's what we are seeing on both the 9123, and the 9125 (although the 9123 seems to be worse). Also 130M per second total throughput on a device which should have around 500M per second throughput seems like very low performance to me. If the processor is capable of handling 350M/second+ throughput, then that looks more like a performance bug with the PMP support to me? > However if you configure the drives in a RAID configuration using the 9123 RAID utility you should see better performance than with 9125. > The drives in the machine are using Linux's software RAID6 (26 drives in the machine in total - multiple controllers). The 9123-based cards were selected because they were more readily available and cheaper. Just straight AHCI passthrough is all I want to work here, and the firmware version installed on the 9123 cards I have doesn't support RAID AFAIK, it just does plain AHCI. And going back to the 9125 - the performance with that is unreliable unless you turn off NCQ, and more seriously, sometimes reads are failed entirely. These are the 88SE9125 results again with 2.6.38 and the default Linux NCQ depth of 31, whilst reading a single drive at a time from behind a 3726 PMP: Timing buffered disk reads: 386 MB in 3.00 seconds = 128.59 MB/sec Timing buffered disk reads: 38 MB in 7.01 seconds = 5.42 MB/sec Timing buffered disk reads: read(2097152) returned 823296 bytes BLKFLSBUF failed: No such device ^^ i.e. a read failure, see the previous emails for the associated kernel error messages Timing buffered disk reads: 328 MB in 3.55 seconds = 92.29 MB/sec Timing buffered disk reads: 204 MB in 5.30 seconds = 38.48 MB/sec Timing buffered disk reads: 376 MB in 3.01 seconds = 124.78 MB/sec Timing buffered disk reads: 200 MB in 3.01 seconds = 66.53 MB/sec Timing buffered disk reads: 276 MB in 3.01 seconds = 91.68 MB/sec Timing buffered disk reads: 154 MB in 3.36 seconds = 45.81 MB/sec Timing buffered disk reads: 384 MB in 3.01 seconds = 127.45 MB/sec Timing buffered disk reads: 358 MB in 3.01 seconds = 119.03 MB/sec Timing buffered disk reads: 392 MB in 3.00 seconds = 130.65 MB/sec Timing buffered disk reads: 364 MB in 4.33 seconds = 84.11 MB/sec Timing buffered disk reads: 188 MB in 3.01 seconds = 62.44 MB/sec Timing buffered disk reads: 342 MB in 3.01 seconds = 113.47 MB/sec Timing buffered disk reads: 392 MB in 3.01 seconds = 130.39 MB/sec Timing buffered disk reads: 394 MB in 3.01 seconds = 130.76 MB/sec Timing buffered disk reads: 274 MB in 3.91 seconds = 70.16 MB/sec Timing buffered disk reads: 392 MB in 3.00 seconds = 130.50 MB/sec Please could you acknowledge that there is actually a problem here? I don't know whether it's with the 88SE91xx controllers, or with the Linux AHCI driver (or Linux PMP support), but this is clearly not correct behaviour. This fault doesn't appear when using a SiI3132, or an 88SX7042. I don't currently have a different AHCI+FBS capable controller to double-check against, but may be able to check against an Intel one in a couple of weeks time. Thanks, Tim. -- To unsubscribe from this list: send the line "unsubscribe linux-ide" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Hello, On Fri, Jul 08, 2011 at 10:53:01AM +0100, Tim Small wrote: > On 08/07/11 05:42, Hubert Bailey wrote: >> The 9125 is a simple controller without a internal processor. The >> 9123 contains an internal processor to enhance RAID 0/1 operations. >> If you are testing in a JBOD configuration you will not take >> advantage of the 9123 internal proces sor. > > OK, that's fine. I have a nice fast CPU in the system which runs the > Linux md code (which I can debug if necessary) with very high > throughput, and it even works across controller cards. A JBOD is what I > want. Yeah, especially for RAID 0/1, there isn't much 'acceleration' to do and with the abundant extra cores and vast amount of main memory these days hardware support for even R5/6 doesn't seem too useful. > Please could you acknowledge that there is actually a problem here? I > don't know whether it's with the 88SE91xx controllers, or with the Linux > AHCI driver (or Linux PMP support), but this is clearly not correct > behaviour. This fault doesn't appear when using a SiI3132, or an > 88SX7042. I don't currently have a different AHCI+FBS capable > controller to double-check against, but may be able to check against an > Intel one in a couple of weeks time. Oh sure, it's not working properly. Looking at the performance numbers you posted for Windows, it seems the Windows driver isn't using FBS either. Larry, Hubert, can you guys please confirm this? Should we blacklist FBS support for some of marvell ahci's? Thanks.
diff --git a/drivers/ata/libahci.c b/drivers/ata/libahci.c index d38c40f..a2f4b68 100644 --- a/drivers/ata/libahci.c +++ b/drivers/ata/libahci.c @@ -444,6 +444,7 @@ void ahci_save_initial_config(struct device *dev, "controller can do FBS, turning on CAP_FBS\n"); cap |= HOST_CAP_FBS; } + cap &= ~HOST_CAP_FBS; if (force_port_map && port_map != force_port_map) { dev_printk(KERN_INFO, dev, "forcing port_map 0x%x -> 0x%x\n",