Jim Bernard wrote:
> Howdy,
> 
>   I've recently added to an old x86 system a PCI SATA controller (VIA VT6421)
> with a single SATA disk (WDC WD5000AAKS) attached.  The system is running
> -current built from sources updated Nov. 17.  The disk works, but the data
> transfer rate is excruciatingly slow, about 4 MB/sec, because the driver uses
> PIO mode 0.
> 
>   Problems appear to begin when the PIO mode support is to be probed
> (ata_set_mode=0xc) and __wdccommand_start waits for WDCS_DRQ to be deasserted
> before actually starting the transfer.  The status read by __wdcwait always
> has the WDCS_DRQ bit set, so the command eventually times out:
> 
>   ata_set_mode=0xc
>   wdc_exec_command viaide1:0:0
>   ata_exec_xfer 0xc1b44f88 channel 0 drive 0
>   atastart from ata_exec_xfer, flags 0x100
>   atastart: xfer 0xc1b44f88 channel 0 drive 0
>   __wdccommand_start viaide1:0:0
>   __wdcwait viaide1:0
>   __wdcwait: viaide1:0: timeout (time=11), status 58 error 0 (mask 0x8 bits 0x0)
>   ...  [previous 2 lines repeated 100 more times]
>   __wdccommand_done viaide1:0:0 flags 0x108
>     [ata_command flag 0x100 is AT_TIMEOU, command timed out]
> 
>   I don't have any alternative SATA drives or controllers to try, but I did
> boot a knoppix (linux) CD, and it is able to transfer data from the disk
> at full speed, about 85 MB/sec.  Thus, the hardware is apparently not
> malfunctioning.
> 
>   So, can anyone offer any suggestions (better yet, code) for fixing this?
> I'll include below a more substantial subset of the dmesg output (lots of
> debugging is turned on), as well as output from "atactl wd2 identify", which
> shows what the drive supports.  I can supply the full dmesg output to anyone
> who is interested.
> 
>   Thanks!
> 
> --Jim
> 
> 
> selected dmesg output:
> 
> ...
> viaide1 at pci0 dev 11 function 0
> ...  [omitted most of pci config dump]
> VIA Technologies VT6421 Serial RAID Controller (RAID mass storage, revision 0x50) at ? dev 11 function 0 (tag 0x80005800, intrtag 0x80005800, intrswiz 0, intrpin 0x1, i/o on, mem on, no quirks)
> viaide1: VIA Technologies VT6421 Serial RAID Controller (rev. 0x50)
> viaide1: bus-master DMA support present
> viaide1: using irq 10 for native-PCI interrupt
> viaide1: primary channel wired to native-PCI mode
> atabus2 at viaide1 channel 0
> viaide1: secondary channel wired to native-PCI mode
> atabus3 at viaide1 channel 1
> ...
> viaide1 port 0: device present, speed: 1.5Gb/s
> viaide1: port 0: scnt=0x1 sn=0x1 cl=0x0 ch=0x0
> viaide1:0:0: after reset, sc=0x1 sn=0x1 cl=0x0 ch=0x0
> viaide1:0:1: after reset, sc=0x0 sn=0x0 cl=0x0 ch=0x0
> viaide1:0: wdcwait_reset() end, st0=0x50 st1=0x0
> ...
> wd2 at atabus2 drive 0wdattach
> ata_get_params
> wdc_exec_command viaide1:0:0
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x100
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> __wdccommand_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xec cylin=0 head=0 sector=0 count=0 features=0
> wdcintr
> __wdccommand_intr viaide1:0:0
> __wdcwait viaide1:0
> __wdccommand_done viaide1:0:0 flags 0x49
> : <WDC WD5000AAKS-00YGA0>
> wd2: drive supports 16-sector PIO transfers, LBA48 addressing
> wd2: 465 GB, 969021 cyl, 16 head, 63 sec, 512 bytes/sect x 976773168 sectors
> wd2: atap_dmatiming_mimi=120, atap_dmatiming_recom=120
> ata_get_params
> wdc_exec_command viaide1:0:0
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x100
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> __wdccommand_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xec cylin=0 head=0 sector=0 count=0 features=0
> wdcintr
> __wdccommand_intr viaide1:0:0
> __wdcwait viaide1:0
> __wdccommand_done viaide1:0:0 flags 0x49
> ata_get_params
> wdc_exec_command viaide1:0:0
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x100
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> __wdccommand_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xec cylin=0 head=0 sector=0 count=0 features=0
> wdcintr
> __wdccommand_intr viaide1:0:0
> __wdcwait viaide1:0
> __wdccommand_done viaide1:0:0 flags 0x49
> ata_set_mode=0xc
> wdc_exec_command viaide1:0:0
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x100
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> __wdccommand_start viaide1:0:0
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status 58 error 0 (mask 0x8 bits 0x0)
> ...  [previous 2 lines repeated 100 more times]
> __wdccommand_done viaide1:0:0 flags 0x108
> ata_set_mode=0xb
> wdc_exec_command viaide1:0:0
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x100
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> __wdccommand_start viaide1:0:0
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status 58 error 0 (mask 0x8 bits 0x0)
> ...  [previous 2 lines repeated 100 more times]
> __wdccommand_done viaide1:0:0 flags 0x108
> wd2(viaide1:0:0): using PIO mode 0
> ...
> wdopen
> ata_get_params
> wdc_exec_command viaide1:0:0
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x0
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> __wdccommand_start viaide1:0:0
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status 58 error 0 (mask 0x48 bits 0x40)
> __wdccommand_start viaide1:0:0
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status 58 error 0 (mask 0x48 bits 0x40)
> ...  [previous 2 lines repeated 300 more times]
> __wdccommand_done viaide1:0:0 flags 0x109
> ata_get_parms: ata_c.flags=0x129
> wdgetdisklabel
> wdgetdefaultlabel
> wdstrategy (wd2)
> wdstart wd2
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x0
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> wdc_ata_bio_start viaide1:0:0
> wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommandshort viaide1:0:0 command 0x10
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xc6 cylin=0 head=0 sector=0 count=16 features=0
> __wdcwait viaide1:0
> _wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0x20 cylin=0 head=64 sector=0 count=1 features=0
> wdctimeout
> viaide1:0:0: lost interrupt
> 	type: ata tc_bcount: 512 tc_skip: 0
> wdc_ata_bio_intr viaide1:0:0
> wdc_ata_bio_done viaide1:0:0: flags 0x2
> wdc_ata_done: drv_done
> wddone wd2
> wdc_reset_drive viaide1:0 for drive 0
> wd2d: device timeout reading fsbn 0 (wd2 bn 0; cn 0 tn 0 sn 0), retrying
> atastart from wdc_ata_done, flags 0x200
> viaide1:0:0: after reset, sc=0x1 sn=0x1 cl=0x0 ch=0x0
> viaide1:0:1: after reset, sc=0x0 sn=0x0 cl=0x0 ch=0x0
> viaide1:0: wdcwait_reset() end, st0=0x50 st1=0x0
> wdrestart wd2
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x0
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> wdc_ata_bio_start viaide1:0:0
> wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommandshort viaide1:0:0 command 0x10
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status d0 error 1 (mask 0x40 bits 0x40)
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status d0 error 1 (mask 0x40 bits 0x40)
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status d0 error 1 (mask 0x40 bits 0x40)
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xc6 cylin=0 head=0 sector=0 count=16 features=0
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: did busy-wait, time=1
> _wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0x20 cylin=0 head=64 sector=0 count=1 features=0
> wdcintr
> wdc_ata_bio_intr viaide1:0:0
> __wdcwait viaide1:0
> wdc_ata_bio_done viaide1:0:0: flags 0x0
> wdc_ata_done: drv_done
> wddone wd2
> wd2: soft error (corrected)
> wdstart wd2
> atastart from wdc_ata_done, flags 0x0
> wdstrategy (wd2)
> wdstart wd2
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x0
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> wdc_ata_bio_start viaide1:0:0
> _wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xc4 cylin=0 head=64 sector=63 count=2 features=0
> wdcintr
> wdc_ata_bio_intr viaide1:0:0
> __wdcwait viaide1:0
> wdc_ata_bio_done viaide1:0:0: flags 0x0
> wdc_ata_done: drv_done
> wddone wd2
> wdstart wd2
> atastart from wdc_ata_done, flags 0x0
> wdstrategy (wd2)
> wdstart wd2
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x0
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> wdc_ata_bio_start viaide1:0:0
> _wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommandext viaide1:0:0: command=0x24 blkno=976773167 count=1
> wdcintr
> wdc_ata_bio_intr viaide1:0:0
> __wdcwait viaide1:0
> wdc_ata_bio_done viaide1:0:0: flags 0x0
> wdc_ata_done: drv_done
> wddone wd2
> wdstart wd2
> atastart from wdc_ata_done, flags 0x0
> wdioctl
> wdioctl
> wdstrategy (wd2)
> wdstart wd2
> ata_exec_xfer 0xc1b44f88 channel 0 drive 0
> atastart from ata_exec_xfer, flags 0x0
> atastart: xfer 0xc1b44f88 channel 0 drive 0
> wdc_ata_bio_start viaide1:0:0
> wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommandshort viaide1:0:0 command 0x10
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status d0 error 0 (mask 0x40 bits 0x40)
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status d0 error 0 (mask 0x40 bits 0x40)
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: timeout (time=11), status d0 error 0 (mask 0x40 bits 0x40)
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xc6 cylin=0 head=0 sector=0 count=16 features=0
> __wdcwait viaide1:0
> __wdcwait: viaide1:0: did busy-wait, time=1
> _wdc_ata_bio_start viaide1:0:0
> __wdcwait viaide1:0
> wdccommand viaide1:0:0: command=0xc4 cylin=0 head=64 sector=64 count=4 features=0
> wdcintr
> wdc_ata_bio_intr viaide1:0:0
> __wdcwait viaide1:0
> wdc_ata_bio_done viaide1:0:0: flags 0x0
> wdc_ata_done: drv_done
> wddone wd2
> wdstart wd2
> atastart from wdc_ata_done, flags 0x0
> wdclose
> 
> =================================================
> % atactl wd2 identify
> Model: WDC WD5000AAKS-00YGA0, Rev: 12.01C02, Serial #:      WD-WCAS81254899
> Device type: ATA, fixed
> Device supports command queue depth of 31
> Device capabilities:
> 	DMA
> 	LBA
> 	ATA standby timer values
> 	IORDY operation
> 	IORDY disabling
> Device supports following standards:
> ATA-1 ATA-2 ATA-3 ATA-4 ATA-5 ATA-6 ATA-7 
> Command set support:
> 	NOP command (enabled)
> 	READ BUFFER command (enabled)
> 	WRITE BUFFER command (enabled)
> 	Host Protected Area feature set (enabled)
> 	look-ahead (enabled)
> 	write cache (enabled)
> 	Power Management feature set (enabled)
> 	Security Mode feature set (disabled)
> 	SMART feature set (enabled)
> 	FLUSH CACHE EXT command (enabled)
> 	FLUSH CACHE command (enabled)
> 	Device Configuration Overlay feature set (enabled)
> 	48-bit Address feature set (enabled)
> 	Automatic Acoustic Management feature set (disabled)
> 	SET MAX security extension (disabled)
> 	SET FEATURES required to spin-up after power-up (enabled)
> 	Power-Up In Standby feature set (disabled)
> 	DOWNLOAD MICROCODE command (enabled)
> 	World Wide name
> 	General Purpose Logging feature set
> 	SMART self-test
> 	SMART error logging
> Serial ATA capabilities:
> 	1.5Gb/s signaling
> 	3.0Gb/s signaling
> 	Native Command Queuing
> 	Host-Initiated Interface Power Management
> 	PHY Event Counters
> Serial ATA features:
> 	DMA Setup Auto Activate (disabled)
> 	Software Settings Preservation (enabled)
> 

Hi,

Just a thought.  Most new SATA drives come with a 150/300 interface 
speed jumper.  As I believe the controller is 150 only, ensure that the 
drive is set to 150 as well.

Hope that helps,
skd