sata_sil24 failed command: READ FPDMA QUEUED

sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

Today I plugged in a brand new sil3132 controller (LYCOM SATA PE-103 2-CH) 
in my server, put it in the secondary graphics-card 16x PCI-Express slot 
(I wanted to find out if it worked there), hooked port 0 up to a PMP and 
attached two disks on port 0 and 1 and powered my server on.

After getting alot of errors at kernel start when it was detecting the 
disks (not saved, sorry) I started to eliminate things and narrow it down:

* SATA-controller is now in a "normal" 1x PCI-Express slot.
* No PMP, just one disk now attached to port 0 on the controller.
* Switched SATA-cable.
* Switched to a different disk (different vendor)

All disks I tried works fine on the motherboard ICH8 controler.

A google for the error message did not turn up alot of interesting 
results, trying my luck here instead, to see if anyone has any ideas.

Please let me know if you need any more output, or if you have something 
you want me to try.

Full "dmesg" output and kernel-config available at http://tlund.pp.se/sil24/

uname -a
========
Linux server 2.6.32.16 #3 SMP Tue Jul 13 21:14:20 CEST 2010 x86_64 GNU/Linux

SATA-controller as shown by "lcpci -v"
======================================
01:00.0 SATA controller: Silicon Image, Inc. SiI 3132 Serial ATA Raid II Controller (rev 01) (prog-if 00 [Vendor specific])
         Subsystem: Silicon Image, Inc. SiI 3132 Serial ATA Raid II Controller
         Flags: bus master, fast devsel, latency 0, IRQ 16
         Memory at f1004000 (64-bit, non-prefetchable) [size=128]
         Memory at f1000000 (64-bit, non-prefetchable) [size=16K]
         I/O ports at 8000 [size=128]
         [virtual] Expansion ROM at f8200000 [disabled] [size=512K]
         Capabilities: [54] Power Management version 2
         Capabilities: [5c] Message Signalled Interrupts: Mask- 64bit+ Queue=0/0 Enable-
         Capabilities: [70] Express Legacy Endpoint, MSI 00
         Capabilities: [100] Advanced Error Reporting <?>
         Kernel driver in use: sata_sil24

"dmesg" output (relevant? parts)
================================
Linux version 2.6.32.16 (root@server) (gcc version 4.3.2 (Debian 4.3.2-1.1) ) #3 SMP Tue Jul 13 21:14:20 CEST 2010
<..>
sata_sil24 0000:02:00.0: version 1.1
sata_sil24 0000:02:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
sata_sil24 0000:02:00.0: setting latency timer to 64
<..>
scsi8 : sata_sil24
scsi9 : sata_sil24
ata9: SATA max UDMA/100 host m128@0xf1004000 port 0xf1000000 irq 17
ata10: SATA max UDMA/100 host m128@0xf1004000 port 0xf1002000 irq 17
<..>
ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
ata9.00: ATA-8: SAMSUNG HD103SJ, 1AJ10001, max UDMA/133
ata9.00: 1953525168 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata9.00: configured for UDMA/100
scsi 8:0:0:0: Direct-Access     ATA      SAMSUNG HD103SJ  1AJ1 PQ: 0 ANSI: 5
sd 8:0:0:0: [sdb] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
sd 8:0:0:0: Attached scsi generic sg1 type 0
sd 8:0:0:0: [sdb] Write Protect is off
sd 8:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 8:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sdb:
ata9.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00020002, device error via D2H FIS
ata9.00: failed command: READ FPDMA QUEUED
ata9.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 50/00:00:00:00:00/00:00:00:00:00/00 Emask 0x401 (device error) <F>
ata9.00: status: { DRDY }
ata9.00: configured for UDMA/100
ata9: EH complete
ata10: SATA link down (SStatus 0 SControl 0)
ata9.00: NCQ disabled due to excessive errors
ata9.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen
ata9.00: failed command: READ FPDMA QUEUED
ata9.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata9.00: status: { DRDY }
ata9: hard resetting link
ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00020002, device error via D2H FIS
ata9.00: failed command: READ DMA
ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
          res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
ata9.00: status: { DRDY ERR }
ata9.00: error: { ABRT }
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00060002, device error via D2H FIS
ata9.00: failed command: READ DMA
ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
          res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
ata9.00: status: { DRDY ERR }
ata9.00: error: { ABRT }
ata9.00: configured for UDMA/100
ata9: EH complete
<..and it goes on..>

Best regards,
Tomas

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Robert Hancock]

On 07/13/2010 03:09 PM, Tomas Lund wrote:
> Today I plugged in a brand new sil3132 controller (LYCOM SATA PE-103
> 2-CH) in my server, put it in the secondary graphics-card 16x
> PCI-Express slot (I wanted to find out if it worked there), hooked port
> 0 up to a PMP and attached two disks on port 0 and 1 and powered my
> server on.
>
> After getting alot of errors at kernel start when it was detecting the
> disks (not saved, sorry) I started to eliminate things and narrow it down:
>
> * SATA-controller is now in a "normal" 1x PCI-Express slot.
> * No PMP, just one disk now attached to port 0 on the controller.
> * Switched SATA-cable.
> * Switched to a different disk (different vendor)
>
> All disks I tried works fine on the motherboard ICH8 controler.

...

> ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
> ata9.00: irq_stat 0x00020002, device error via D2H FIS
> ata9.00: failed command: READ DMA
> ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
> res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
> ata9.00: status: { DRDY ERR }
> ata9.00: error: { ABRT }
> ata9.00: configured for UDMA/100
> ata9: EH complete

This seems strange, the drive apparently reported command aborted when 
trying to read the first sectors of the disk, but there's no indication 
of why (there's nothing set in Serror).

Can you test the controller in a different machine? It could be faulty..

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

On Tue, 13 Jul 2010, Robert Hancock wrote:

> On 07/13/2010 03:09 PM, Tomas Lund wrote:
>
>> ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>> ata9.00: irq_stat 0x00020002, device error via D2H FIS
>> ata9.00: failed command: READ DMA
>> ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
>> res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
>> ata9.00: status: { DRDY ERR }
>> ata9.00: error: { ABRT }
>> ata9.00: configured for UDMA/100
>> ata9: EH complete
>
> This seems strange, the drive apparently reported command aborted when 
> trying to read the first sectors of the disk, but there's no indication 
> of why (there's nothing set in Serror).
>
> Can you test the controller in a different machine? It could be faulty..

Remotly compiled 2.6.27.48 and rebooted, just to test, and the problem 
persists.

Will pick up another sil3132 based-controller (different vendor) at lunch 
today and do more testing tonight.

The motherboard in the server is a Gigabyte 965P-DS4 with a 2.13GHz 
Core2Duo E6420

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

On Wed, 14 Jul 2010, Tomas Lund wrote:

> On Tue, 13 Jul 2010, Robert Hancock wrote:
>
>> On 07/13/2010 03:09 PM, Tomas Lund wrote:
>> 
>>> ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
>>> ata9.00: irq_stat 0x00020002, device error via D2H FIS
>>> ata9.00: failed command: READ DMA
>>> ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
>>> res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
>>> ata9.00: status: { DRDY ERR }
>>> ata9.00: error: { ABRT }
>>> ata9.00: configured for UDMA/100
>>> ata9: EH complete
>> 
>> This seems strange, the drive apparently reported command aborted when 
>> trying to read the first sectors of the disk, but there's no indication 
>> of why (there's nothing set in Serror).
>> 
>> Can you test the controller in a different machine? It could be 
>> faulty..
>
> Remotly compiled 2.6.27.48 and rebooted, just to test, and the problem 
> persists.
>
> Will pick up another sil3132 based-controller (different vendor) at 
> lunch today and do more testing tonight.
>
> The motherboard in the server is a Gigabyte 965P-DS4 with a 2.13GHz 
> Core2Duo E6420

Got myself a "Sunix SATA2400" controller with the same chip on it:

02:00.0 RAID bus controller [0104]: Silicon Image, Inc. SiI 3132 Serial ATA Raid II Controller [1095:3132] (rev 01)
         Subsystem: Silicon Image, Inc. Device [1095:7132]
         Flags: bus master, fast devsel, latency 0, IRQ 17
         Memory at f1004000 (64-bit, non-prefetchable) [size=128]
         Memory at f1000000 (64-bit, non-prefetchable) [size=16K]
         I/O ports at 8000 [size=128]
         [virtual] Expansion ROM at f8200000 [disabled] [size=512K]
         Capabilities: [54] Power Management version 2
         Capabilities: [5c] Message Signalled Interrupts: Mask- 64bit+ Queue=0/0 Enable-
         Capabilities: [70] Express Legacy Endpoint, MSI 00
         Capabilities: [100] Advanced Error Reporting <?>
         Kernel driver in use: sata_sil24

dmesg output from booting:

sata_sil24 0000:02:00.0: version 1.1
sata_sil24 0000:02:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
sata_sil24 0000:02:00.0: setting latency timer to 64
scsi8 : sata_sil24
scsi9 : sata_sil24
ata9: SATA max UDMA/100 host m128@0xf1004000 port 0xf1000000 irq 17
ata10: SATA max UDMA/100 host m128@0xf1004000 port 0xf1002000 irq 17
ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
ata9.00: ATA-8: SAMSUNG HD103SJ, 1AJ10001, max UDMA/133
ata9.00: 1953525168 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata9.00: configured for UDMA/100
ata10: SATA link down (SStatus 0 SControl 0)
scsi 8:0:0:0: Direct-Access     ATA      SAMSUNG HD103SJ  1AJ1 PQ: 0 ANSI: 5
sd 8:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
sd 8:0:0:0: [sdb] Write Protect is off
sd 8:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 8:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 8:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
sd 8:0:0:0: [sdb] Write Protect is off
sd 8:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 8:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sdb:<3>ata9.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00020002, device error via D2H FIS
ata9.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 50/00:00:00:00:00/00:00:00:00:00/00 Emask 0x401 (device error) <F>
ata9.00: status: { DRDY }
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: NCQ disabled due to excessive errors
ata9.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen
ata9.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata9.00: status: { DRDY }
ata9: hard resetting link
ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00020002, device error via D2H FIS
ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
          res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
ata9.00: status: { DRDY ERR }
ata9.00: error: { ABRT }
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00060002, device error via D2H FIS
ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
          res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
ata9.00: status: { DRDY ERR }
ata9.00: error: { ABRT }
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00060002, device error via D2H FIS
ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
          res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
ata9.00: status: { DRDY ERR }
ata9.00: error: { ABRT }
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00060002, device error via D2H FIS
ata9.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
          res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
ata9.00: status: { DRDY ERR }
ata9.00: error: { ABRT }
ata9.00: configured for UDMA/100
sd 8:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
sd 8:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Descriptor sense data with sense descriptors (in hex):
         72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
         00 00 00 00 
sd 8:0:0:0: [sdb] Add. Sense: No additional sense information
end_request: I/O error, dev sdb, sector 0
Buffer I/O error on device sdb, logical block 0
ata9: EH complete
<..continues..>

I will go ahead and test this disk and sata-cable with both of the controlers on a different motherboard.

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

I have now tried both of my sil3132-based controllers with a different 
motherboard (Asus P6T Core i7) and I get the same problem with both of 
them. I tested them with different disks.

"dmesg" output from booting at http://tlund.pp.se/sil24/dmesg2.txt and 
http://tlund.pp.se/sil24/dmesg3.txt

The tests on the P6T motherboard were made with the same 2.6.27.48 kernel 
that I reverted to on the real server and I am starting to think that it 
might be something in my configuration that makes it not work? Two 
different controllers on two different motherboards with two different 
disks?

Full config at http://tlund.pp.se/sil24/config_2.6.27.48.txt

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

Put the "LYCOM SATA PE-103 2-CH" back in the server with the Gigabyte 
965P-DS4 motherboard and installed the debian backports kernel 
2.6.32-bpo.5-amd64.

Problem persists and a dmesg and console output (since dmesg buffer is too 
small to fit everything) is available at:

http://tlund.pp.se/sil24/console_2.6.32-bpo.5-amd64.txt
http://tlund.pp.se/sil24/dmesg_2.6.32-bpo.5-amd64.txt

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

On Wed, 21 Jul 2010, Tomas Lund wrote:

> Put the "LYCOM SATA PE-103 2-CH" back in the server with the Gigabyte 
> 965P-DS4 motherboard and installed the debian backports kernel 
> 2.6.32-bpo.5-amd64.
>
> Problem persists and a dmesg and console output (since dmesg buffer is too 
> small to fit everything) is available at:
>
> http://tlund.pp.se/sil24/console_2.6.32-bpo.5-amd64.txt
> http://tlund.pp.se/sil24/dmesg_2.6.32-bpo.5-amd64.txt

Tested Debian 2.6.26-2-amd64, files at the same place.

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Robert Hancock]

On 07/21/2010 06:38 AM, Tomas Lund wrote:
> On Wed, 21 Jul 2010, Tomas Lund wrote:
>
>> Put the "LYCOM SATA PE-103 2-CH" back in the server with the Gigabyte
>> 965P-DS4 motherboard and installed the debian backports kernel
>> 2.6.32-bpo.5-amd64.
>>
>> Problem persists and a dmesg and console output (since dmesg buffer is
>> too small to fit everything) is available at:
>>
>> http://tlund.pp.se/sil24/console_2.6.32-bpo.5-amd64.txt
>> http://tlund.pp.se/sil24/dmesg_2.6.32-bpo.5-amd64.txt
>
> Tested Debian 2.6.26-2-amd64, files at the same place.

What does "hdparm -I" show when run on the drive attached to that 
controller? Is it possible there's some security locking enabled on it? 
If the BIOS is doing some kind of security unlock then it probably does 
it only on drives attached to the motherboard controller, not on any 
add-in cards. It certainly seems like the drive is returning command 
aborted on all reads when connected to that controller for whatever reason.

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

On Fri, 30 Jul 2010, Robert Hancock wrote:

> On 07/21/2010 06:38 AM, Tomas Lund wrote:
>> On Wed, 21 Jul 2010, Tomas Lund wrote:
>> 
>>> Put the "LYCOM SATA PE-103 2-CH" back in the server with the Gigabyte 
>>> 965P-DS4 motherboard and installed the debian backports kernel 
>>> 2.6.32-bpo.5-amd64.
>>> 
>>> Problem persists and a dmesg and console output (since dmesg buffer is 
>>> too small to fit everything) is available at:
>>> 
>>> http://tlund.pp.se/sil24/console_2.6.32-bpo.5-amd64.txt
>>> http://tlund.pp.se/sil24/dmesg_2.6.32-bpo.5-amd64.txt
>> 
>> Tested Debian 2.6.26-2-amd64, files at the same place.
>
> What does "hdparm -I" show when run on the drive attached to that controller?

# hdparm -I /dev/sdb

/dev/sdb:

ATA device, with non-removable media
         Model Number:       SAMSUNG HD103SJ
         Serial Number:      S246J90Z321275
         Firmware Revision:  1AJ10001
         Transport:          Serial, ATA8-AST, SATA 1.0a, SATA II Extensions, SATA Rev 2.5
Standards:
         Used: unknown (minor revision code 0x0028)
         Supported: 8 7 6 5
         Likely used: 8
Configuration:
         Logical         max     current
         cylinders       16383   16383
         heads           16      16
         sectors/track   63      63
         --
         CHS current addressable sectors:   16514064
         LBA    user addressable sectors:  268435455
         LBA48  user addressable sectors: 1953525168
         device size with M = 1024*1024:      953869 MBytes
         device size with M = 1000*1000:     1000204 MBytes (1000 GB)
Capabilities:
         LBA, IORDY(can be disabled)
         Queue depth: 32
         Standby timer values: spec'd by Standard, no device specific minimum
         R/W multiple sector transfer: Max = 16  Current = 16
         Advanced power management level: disabled
         Recommended acoustic management value: 254, current value: 254
         DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 *udma5 udma6
              Cycle time: min=120ns recommended=120ns
         PIO: pio0 pio1 pio2 pio3 pio4
              Cycle time: no flow control=120ns  IORDY flow control=120ns
Commands/features:
         Enabled Supported:
            *    SMART feature set
            *    Security Mode feature set
            *    Power Management feature set
            *    Write cache
            *    Look-ahead
            *    Host Protected Area feature set
            *    WRITE_BUFFER command
            *    READ_BUFFER command
            *    NOP cmd
            *    DOWNLOAD_MICROCODE
                 Advanced Power Management feature set
                 Power-Up In Standby feature set
            *    SET_FEATURES required to spinup after power up
                 SET_MAX security extension
            *    Automatic Acoustic Management feature set
            *    48-bit Address feature set
            *    Device Configuration Overlay feature set
            *    Mandatory FLUSH_CACHE
            *    FLUSH_CACHE_EXT
            *    SMART error logging
            *    SMART self-test
            *    General Purpose Logging feature set
            *    64-bit World wide name
            *    WRITE_UNCORRECTABLE_EXT command
            *    {READ,WRITE}_DMA_EXT_GPL commands
            *    Segmented DOWNLOAD_MICROCODE
            *    SATA-I signaling speed (1.5Gb/s)
            *    SATA-II signaling speed (3.0Gb/s)
            *    Native Command Queueing (NCQ)
            *    Host-initiated interface power management
            *    Phy event counters
            *    unknown 76[12]
                 DMA Setup Auto-Activate optimization
                 Device-initiated interface power management
            *    Software settings preservation
            *    SMART Command Transport (SCT) feature set
            *    SCT Long Sector Access (AC1)
            *    SCT LBA Segment Access (AC2)
            *    SCT Error Recovery Control (AC3)
            *    SCT Features Control (AC4)
            *    SCT Data Tables (AC5)
Security:
         Master password revision code = 65534
                 supported
                 enabled
                 locked
         not     frozen
         not     expired: security count
                 supported: enhanced erase
         Security level high
         150min for SECURITY ERASE UNIT. 150min for ENHANCED SECURITY ERASE UNIT.
Logical Unit WWN Device Identifier: 50024e9221d12b7
         NAA             : 5
         IEEE OUI        : 24e9
         Unique ID       : 221d12b7
Checksum: correct

> Is it possible there's some security locking enabled on it? If the BIOS is 
> doing some kind of security unlock then it probably does it only on drives 
> attached to the motherboard controller, not on any add-in cards. It certainly 
> seems like the drive is returning command aborted on all reads when connected 
> to that controller for whatever reason.

No, nothing like that :(

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Tomas Lund]

Upgraded motherboard (965P-DS4) BIOS to latest version. Booted 2.6.27.48 
with one disk attached to motherboard sata controller (with root 
filesystem) and two disks (different vendors Samsung/WDC) on the 
SIL-controler:

<..>

sata_sil24 0000:03:00.0: version 1.1
sata_sil24 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
sata_sil24 0000:03:00.0: setting latency timer to 64
scsi8 : sata_sil24
scsi9 : sata_sil24
ata9: SATA max UDMA/100 host m128@0xf8004000 port 0xf8000000 irq 17
ata10: SATA max UDMA/100 host m128@0xf8004000 port 0xf8002000 irq 17
ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
ata9.00: ATA-8: SAMSUNG HD103SJ, 1AJ10001, max UDMA/133
ata9.00: 1953525168 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata9.00: configured for UDMA/100
ata10: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
ata10.00: ATA-8: WDC WD20EARS-00S8B1, 80.00A80, max UDMA/133
ata10.00: 3907029168 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata10.00: configured for UDMA/100
scsi 8:0:0:0: Direct-Access     ATA      SAMSUNG HD103SJ  1AJ1 PQ: 0 ANSI: 5
sd 8:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
sd 8:0:0:0: [sdb] Write Protect is off
sd 8:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 8:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 8:0:0:0: [sdb] 1953525168 512-byte hardware sectors (1000205 MB)
sd 8:0:0:0: [sdb] Write Protect is off
sd 8:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 8:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sdb:<3>ata9.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata9.00: irq_stat 0x00020002, device error via D2H FIS
ata9.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 50/00:00:00:00:00/00:00:00:00:00/00 Emask 0x401 (device error) <F>
ata9.00: status: { DRDY }
ata9.00: configured for UDMA/100
ata9: EH complete
ata9.00: NCQ disabled due to excessive errors
ata9.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen
ata9.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata9.00: status: { DRDY }
ata9: hard resetting link
ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
ata9.00: configured for UDMA/100
ata9: EH complete

<..>

scsi 9:0:0:0: Direct-Access     ATA      WDC WD20EARS-00S 80.0 PQ: 0 ANSI: 5
sd 9:0:0:0: [sdc] 3907029168 512-byte hardware sectors (2000399 MB)
sd 9:0:0:0: [sdc] Write Protect is off
sd 9:0:0:0: [sdc] Mode Sense: 00 3a 00 00
sd 9:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 9:0:0:0: [sdc] 3907029168 512-byte hardware sectors (2000399 MB)
sd 9:0:0:0: [sdc] Write Protect is off
sd 9:0:0:0: [sdc] Mode Sense: 00 3a 00 00
sd 9:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
  sdc:<3>ata10: failed to read log page 10h (errno=-2)
ata10.00: exception Emask 0x1 SAct 0x1 SErr 0x0 action 0x0
ata10.00: irq_stat 0x00020002, device error via D2H FIS
ata10.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 51/04:00:af:88:e0/00:00:e8:00:00/e0 Emask 0x1 (device error)
ata10.00: status: { DRDY ERR }
ata10.00: error: { ABRT }
ata10.00: configured for UDMA/100
ata10: EH complete
ata10: failed to read log page 10h (errno=-2)
ata10.00: NCQ disabled due to excessive errors
ata10.00: exception Emask 0x1 SAct 0x1 SErr 0x0 action 0x0
ata10.00: irq_stat 0x00060002, device error via D2H FIS
ata10.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0 ncq 4096 in
          res 51/04:00:af:88:e0/00:00:e8:00:00/e0 Emask 0x1 (device error)
ata10.00: status: { DRDY ERR }
ata10.00: error: { ABRT }
ata10.00: configured for UDMA/100
ata10: EH complete
ata10.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata10.00: irq_stat 0x00060002, device error via D2H FIS
ata10.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
          res 51/04:08:00:00:00/00:00:00:00:00/e0 Emask 0x1 (device error)
ata10.00: status: { DRDY ERR }
ata10.00: error: { ABRT }
ata10.00: configured for UDMA/100
ata10: EH complete

<..>

Starting to get a bit desperate, willing to try anything..

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED

[Robert Hancock]

On Sun, Aug 1, 2010 at 8:27 AM, Tomas Lund <tlund@nxs.se> wrote:
> On Fri, 30 Jul 2010, Robert Hancock wrote:
>
>> On 07/21/2010 06:38 AM, Tomas Lund wrote:
>>>
>>> On Wed, 21 Jul 2010, Tomas Lund wrote:
>>>
>>>> Put the "LYCOM SATA PE-103 2-CH" back in the server with the Gigabyte
>>>> 965P-DS4 motherboard and installed the debian backports kernel
>>>> 2.6.32-bpo.5-amd64.
>>>>
>>>> Problem persists and a dmesg and console output (since dmesg buffer is
>>>> too small to fit everything) is available at:
>>>>
>>>> http://tlund.pp.se/sil24/console_2.6.32-bpo.5-amd64.txt
>>>> http://tlund.pp.se/sil24/dmesg_2.6.32-bpo.5-amd64.txt
>>>
>>> Tested Debian 2.6.26-2-amd64, files at the same place.
>>
>> What does "hdparm -I" show when run on the drive attached to that
>> controller?
>
> # hdparm -I /dev/sdb
>
> /dev/sdb:
>
> ATA device, with non-removable media
>        Model Number:       SAMSUNG HD103SJ
>        Serial Number:      S246J90Z321275
>        Firmware Revision:  1AJ10001
>        Transport:          Serial, ATA8-AST, SATA 1.0a, SATA II Extensions,
> SATA Rev 2.5
> Standards:
>        Used: unknown (minor revision code 0x0028)
>        Supported: 8 7 6 5
>        Likely used: 8
> Configuration:
>        Logical         max     current
>        cylinders       16383   16383
>        heads           16      16
>        sectors/track   63      63
>        --
>        CHS current addressable sectors:   16514064
>        LBA    user addressable sectors:  268435455
>        LBA48  user addressable sectors: 1953525168
>        device size with M = 1024*1024:      953869 MBytes
>        device size with M = 1000*1000:     1000204 MBytes (1000 GB)
> Capabilities:
>        LBA, IORDY(can be disabled)
>        Queue depth: 32
>        Standby timer values: spec'd by Standard, no device specific minimum
>        R/W multiple sector transfer: Max = 16  Current = 16
>        Advanced power management level: disabled
>        Recommended acoustic management value: 254, current value: 254
>        DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 *udma5 udma6
>             Cycle time: min=120ns recommended=120ns
>        PIO: pio0 pio1 pio2 pio3 pio4
>             Cycle time: no flow control=120ns  IORDY flow control=120ns
> Commands/features:
>        Enabled Supported:
>           *    SMART feature set
>           *    Security Mode feature set
>           *    Power Management feature set
>           *    Write cache
>           *    Look-ahead
>           *    Host Protected Area feature set
>           *    WRITE_BUFFER command
>           *    READ_BUFFER command
>           *    NOP cmd
>           *    DOWNLOAD_MICROCODE
>                Advanced Power Management feature set
>                Power-Up In Standby feature set
>           *    SET_FEATURES required to spinup after power up
>                SET_MAX security extension
>           *    Automatic Acoustic Management feature set
>           *    48-bit Address feature set
>           *    Device Configuration Overlay feature set
>           *    Mandatory FLUSH_CACHE
>           *    FLUSH_CACHE_EXT
>           *    SMART error logging
>           *    SMART self-test
>           *    General Purpose Logging feature set
>           *    64-bit World wide name
>           *    WRITE_UNCORRECTABLE_EXT command
>           *    {READ,WRITE}_DMA_EXT_GPL commands
>           *    Segmented DOWNLOAD_MICROCODE
>           *    SATA-I signaling speed (1.5Gb/s)
>           *    SATA-II signaling speed (3.0Gb/s)
>           *    Native Command Queueing (NCQ)
>           *    Host-initiated interface power management
>           *    Phy event counters
>           *    unknown 76[12]
>                DMA Setup Auto-Activate optimization
>                Device-initiated interface power management
>           *    Software settings preservation
>           *    SMART Command Transport (SCT) feature set
>           *    SCT Long Sector Access (AC1)
>           *    SCT LBA Segment Access (AC2)
>           *    SCT Error Recovery Control (AC3)
>           *    SCT Features Control (AC4)
>           *    SCT Data Tables (AC5)
> Security:
>        Master password revision code = 65534
>                supported
>                enabled
>                locked
>        not     frozen
>        not     expired: security count
>                supported: enhanced erase
>        Security level high
>        150min for SECURITY ERASE UNIT. 150min for ENHANCED SECURITY ERASE
> UNIT.
> Logical Unit WWN Device Identifier: 50024e9221d12b7
>        NAA             : 5
>        IEEE OUI        : 24e9
>        Unique ID       : 221d12b7
> Checksum: correct
>
>> Is it possible there's some security locking enabled on it? If the BIOS is
>> doing some kind of security unlock then it probably does it only on drives
>> attached to the motherboard controller, not on any add-in cards. It
>> certainly seems like the drive is returning command aborted on all reads
>> when connected to that controller for whatever reason.
>
> No, nothing like that :(

The output above shows that the drive has security enabled and locked,
 so it seems that must be the case, and it won't be accessible unless
it's unlocked. hdparm should be able to disable it, though it seems
you may need a valid password to do it..

Re: sata_sil24 failed command: READ FPDMA QUEUED (resolved)

[Tomas Lund]

On Sun, 1 Aug 2010, Robert Hancock wrote:

> The output above shows that the drive has security enabled and locked, 
> so it seems that must be the case, and it won't be accessible unless 
> it's unlocked. hdparm should be able to disable it, though it seems you 
> may need a valid password to do it..

There is something I did not mention in any of my earlier posts, and that 
is the fact that the server also has had a 3ware controller installed 
(removed as part of fault isolation) and some of the disks has been 
attached to that controller. In the case of the samsung 1tb disk, it was 
attached to the 3ware conroller after it was successfully tested on the 
motherboard sata-controller.

Some googling and testing found that yes, the 3ware controller does indeed 
lock the drives, even if they are just automatically exported as "JBOD".

The following command successfully unlocked my devices:

hdparm --user-master u --security-disable "3wareUserPassword               " /dev/sdb

I have unlocked and tested a total of 4 disks now, both the samsung 1TB 
and 3 of the WDC 2TB disks. Thank you very much! Left to do: test that 
everything is working with the PMP aswell.

Question: Would it be unreasonable to request that the kernel would issue 
the apropriate ATA-commands to a disk as soon as it is detected, and not 
try to read from it if it is locked? It would have been really, really 
nice to just get the error message "drive is locked".

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED (resolved)

[Robert Hancock]

On Mon, Aug 2, 2010 at 1:21 AM, Tomas Lund <tlund@nxs.se> wrote:
> On Sun, 1 Aug 2010, Robert Hancock wrote:
>
>> The output above shows that the drive has security enabled and locked, so
>> it seems that must be the case, and it won't be accessible unless it's
>> unlocked. hdparm should be able to disable it, though it seems you may need
>> a valid password to do it..
>
> There is something I did not mention in any of my earlier posts, and that is
> the fact that the server also has had a 3ware controller installed (removed
> as part of fault isolation) and some of the disks has been attached to that
> controller. In the case of the samsung 1tb disk, it was attached to the
> 3ware conroller after it was successfully tested on the motherboard
> sata-controller.
>
> Some googling and testing found that yes, the 3ware controller does indeed
> lock the drives, even if they are just automatically exported as "JBOD".
>
> The following command successfully unlocked my devices:
>
> hdparm --user-master u --security-disable "3wareUserPassword               "
> /dev/sdb
>
> I have unlocked and tested a total of 4 disks now, both the samsung 1TB and
> 3 of the WDC 2TB disks. Thank you very much! Left to do: test that
> everything is working with the PMP aswell.

Good to hear.

> Question: Would it be unreasonable to request that the kernel would issue
> the apropriate ATA-commands to a disk as soon as it is detected, and not try
> to read from it if it is locked? It would have been really, really nice to
> just get the error message "drive is locked".

It should be possible to indicate that, yes. I'll look into it when I
get a chance, if someone doesn't beat me to it..

Re: sata_sil24 failed command: READ FPDMA QUEUED (resolved)

[Tomas Lund]

On Mon, 2 Aug 2010, Robert Hancock wrote:

> On Mon, Aug 2, 2010 at 1:21 AM, Tomas Lund <tlund@nxs.se> wrote:
>
>> I have unlocked and tested a total of 4 disks now, both the samsung 1TB 
>> and 3 of the WDC 2TB disks. Thank you very much! Left to do: test that 
>> everything is working with the PMP aswell.
>
> Good to hear.

I now have all of my drives up and working, running on the PMP and 
everything is looking perfectly. Thanks again for your help.

>> Question: Would it be unreasonable to request that the kernel would 
>> issue the apropriate ATA-commands to a disk as soon as it is detected, 
>> and not try to read from it if it is locked? It would have been really, 
>> really nice to just get the error message "drive is locked".
>
> It should be possible to indicate that, yes. I'll look into it when I 
> get a chance, if someone doesn't beat me to it..

Perfect!

//tlund

Re: sata_sil24 failed command: READ FPDMA QUEUED (resolved)

[Robert Hancock]

On 08/02/2010 11:33 PM, Tomas Lund wrote:
> On Mon, 2 Aug 2010, Robert Hancock wrote:
> 
>> On Mon, Aug 2, 2010 at 1:21 AM, Tomas Lund <tlund@nxs.se> wrote:
>>
>>> I have unlocked and tested a total of 4 disks now, both the samsung 1TB and 3 of the WDC 2TB disks. Thank you very much! Left to do: test that everything is working with the PMP aswell.
>>
>> Good to hear.
> 
> I now have all of my drives up and working, running on the PMP and everything is looking perfectly. Thanks again for your help.
> 
>>> Question: Would it be unreasonable to request that the kernel would issue the apropriate ATA-commands to a disk as soon as it is detected, and not try to read from it if it is locked? It would have been really, really nice to just get the error message "drive is locked".
>>
>> It should be possible to indicate that, yes. I'll look into it when I get a chance, if someone doesn't beat me to it..
> 
> Perfect!
> 
> //tlund

Can you test this patch out, assuming you still have anything left that's locked
(or can relock one of them to try it out)? It should print out a warning in
dmesg upon recognizing the device if it's in the security locked state.

diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c
index ddf8e48..d4ec163 100644
--- a/drivers/ata/libata-core.c
+++ b/drivers/ata/libata-core.c
@@ -2561,6 +2561,11 @@ int ata_dev_configure(struct ata_device *dev)
                                       dma_dir_string);
        }
 
+       if (print_info && ata_id_security_locked(dev->id))
+               ata_dev_printk(dev, KERN_WARNING,
+                       "appears to have ATA security enabled and locked - "
+                       "media may be inaccessible until unlocked\n");
+
        /* determine max_sectors */
        dev->max_sectors = ATA_MAX_SECTORS;
        if (dev->flags & ATA_DFLAG_LBA48)
diff --git a/include/linux/ata.h b/include/linux/ata.h
index fe6e681..f2359fa 100644
--- a/include/linux/ata.h
+++ b/include/linux/ata.h
@@ -684,6 +684,22 @@ static inline int ata_id_hpa_enabled(const u16 *id)
        return id[ATA_ID_COMMAND_SET_1] & (1 << 10);
 }
 
+static inline int ata_id_security_locked(const u16 *id)
+{
+       /* Yes children, word 83 valid bits cover word 82 data */
+       if ((id[ATA_ID_COMMAND_SET_2] & 0xC000) != 0x4000)
+               return 0;
+       /* And 87 covers 85-87 */
+       if ((id[ATA_ID_CSF_DEFAULT] & 0xC000) != 0x4000)
+               return 0;
+       /* Check command sets enabled as well as supported */
+       if ((id[ATA_ID_CFS_ENABLE_1] & (1 << 1)) == 0)
+               return 0;
+       if ((id[ATA_ID_COMMAND_SET_1] & (1 << 1)) == 0)
+               return 0;
+       return (id[ATA_ID_DLF] & 0x0007) == 0x0007;
+}
+
 static inline int ata_id_has_wcache(const u16 *id)
 {
        /* Yes children, word 83 valid bits cover word 82 data */

Re: sata_sil24 failed command: READ FPDMA QUEUED (resolved)

[Gwendal Grignou]

Hi Robert,

I had the same problem with locked drive earlier, causing a lot of
unnecessary errors. See "Do not send RW commands to locked disks."
thread.
It works right now, but it does not take in account disks with wrong
information in their identify page. I need to improve this patch: the
first IO will go through and the error handler will check the drive is
locked and then set a bit to prevent sending more command until the
UNLOCK command is issued.

Gwendal.

On Thu, Aug 5, 2010 at 10:03 PM, Robert Hancock <hancockrwd@gmail.com> wrote:
> On 08/02/2010 11:33 PM, Tomas Lund wrote:
>> On Mon, 2 Aug 2010, Robert Hancock wrote:
>>
>>> On Mon, Aug 2, 2010 at 1:21 AM, Tomas Lund <tlund@nxs.se> wrote:
>>>
>>>> I have unlocked and tested a total of 4 disks now, both the samsung 1TB and 3 of the WDC 2TB disks. Thank you very much! Left to do: test that everything is working with the PMP aswell.
>>>
>>> Good to hear.
>>
>> I now have all of my drives up and working, running on the PMP and everything is looking perfectly. Thanks again for your help.
>>
>>>> Question: Would it be unreasonable to request that the kernel would issue the apropriate ATA-commands to a disk as soon as it is detected, and not try to read from it if it is locked? It would have been really, really nice to just get the error message "drive is locked".
>>>
>>> It should be possible to indicate that, yes. I'll look into it when I get a chance, if someone doesn't beat me to it..
>>
>> Perfect!
>>
>> //tlund
>
> Can you test this patch out, assuming you still have anything left that's locked
> (or can relock one of them to try it out)? It should print out a warning in
> dmesg upon recognizing the device if it's in the security locked state.
>
> diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c
> index ddf8e48..d4ec163 100644
> --- a/drivers/ata/libata-core.c
> +++ b/drivers/ata/libata-core.c
> @@ -2561,6 +2561,11 @@ int ata_dev_configure(struct ata_device *dev)
>                                       dma_dir_string);
>        }
>
> +       if (print_info && ata_id_security_locked(dev->id))
> +               ata_dev_printk(dev, KERN_WARNING,
> +                       "appears to have ATA security enabled and locked - "
> +                       "media may be inaccessible until unlocked\n");
> +
>        /* determine max_sectors */
>        dev->max_sectors = ATA_MAX_SECTORS;
>        if (dev->flags & ATA_DFLAG_LBA48)
> diff --git a/include/linux/ata.h b/include/linux/ata.h
> index fe6e681..f2359fa 100644
> --- a/include/linux/ata.h
> +++ b/include/linux/ata.h
> @@ -684,6 +684,22 @@ static inline int ata_id_hpa_enabled(const u16 *id)
>        return id[ATA_ID_COMMAND_SET_1] & (1 << 10);
>  }
>
> +static inline int ata_id_security_locked(const u16 *id)
> +{
> +       /* Yes children, word 83 valid bits cover word 82 data */
> +       if ((id[ATA_ID_COMMAND_SET_2] & 0xC000) != 0x4000)
> +               return 0;
> +       /* And 87 covers 85-87 */
> +       if ((id[ATA_ID_CSF_DEFAULT] & 0xC000) != 0x4000)
> +               return 0;
> +       /* Check command sets enabled as well as supported */
> +       if ((id[ATA_ID_CFS_ENABLE_1] & (1 << 1)) == 0)
> +               return 0;
> +       if ((id[ATA_ID_COMMAND_SET_1] & (1 << 1)) == 0)
> +               return 0;
> +       return (id[ATA_ID_DLF] & 0x0007) == 0x0007;
> +}
> +
>  static inline int ata_id_has_wcache(const u16 *id)
>  {
>        /* Yes children, word 83 valid bits cover word 82 data */
>
> --
> 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
>