Regression between 2.6.20 and 2.6.21-rc1: NCQ problem with ahci and Hitachi drive

Regression between 2.6.20 and 2.6.21-rc1: NCQ problem with ahci and Hitachi drive

[Mathieu Bérard]

Hello,
I have and laptop with an ICH6M SATA Controller and an Hitachi hard drive.
While it worked well using the ahci module and with NCQ enabled using
Linux 2.6.20, it does not work anymore (hang at boot) with 2.6.21-rc*

My drive is among those that were recently blacklisted (see lkml post
"[PATCH] libata:
add NCQ blacklist entries from Silicon Image Windowsdriver)
(Model Number: HTS541010G9SA00 and Firmware Revision: MBZOC60D)
This blacklisting patch is in -mm now.
So there is probably a drive related issue here, I'm just wondering why
it just work
flawlessly with a 2.6.20...

Relevant part of kernel log:
2.6.20:
[   41.076963] SCSI subsystem initialized
[   41.083119] ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 19 (level,
low) -> IRQ 19
[   42.083637] ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 4 ports 1.5
Gbps 0x5 impl IDE mode
[   42.083695] ahci 0000:00:1f.2: flags: 64bit ncq pm led slum part
[   42.083825] ata1: SATA max UDMA/133 cmd 0xF8872D00 ctl 0x0 bmdma 0x0
irq 19
[   42.083938] ata2: SATA max UDMA/133 cmd 0xF8872D80 ctl 0x0 bmdma 0x0
irq 19
[   42.084049] ata3: SATA max UDMA/133 cmd 0xF8872E00 ctl 0x0 bmdma 0x0
irq 19
[   42.084165] ata4: SATA max UDMA/133 cmd 0xF8872E80 ctl 0x0 bmdma 0x0
irq 19
[   42.084221] scsi0 : ahci
[   42.541356] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[   42.542404] ata1.00: ATA-7, max UDMA/100, 195371568 sectors: LBA48
NCQ (depth 31/32)
[   42.542460] ata1.00: ata1: dev 0 multi count 0
[   42.543731] ata1.00: configured for UDMA/100
[   42.543781] scsi1 : ahci
[   42.846169] ata2: SATA link down (SStatus 0 SControl 0)
[   42.846223] scsi2 : ahci
[   43.148995] ata3: SATA link down (SStatus 0 SControl 300)
[   43.149049] scsi3 : ahci
[   43.451821] ata4: SATA link down (SStatus 0 SControl 0)
[   43.451957] scsi 0:0:0:0: Direct-Access     ATA      HTS541010G9SA00 
MBZO PQ: 0 ANSI: 5
[   43.487465] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[   43.487544] sda: Write Protect is off
[   43.487810] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[   43.488805] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[   43.488879] sda: Write Protect is off
[   43.489462] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA

2.6.21-rc1:
[   14.580991] SCSI subsystem initialized
[   14.586026] ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 19 (level,
low) -> IRQ 19
[   15.586790] ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 4 ports 1.5
Gbps 0x5 impl IDE mode
[   15.586847] ahci 0000:00:1f.2: flags: 64bit ncq pm led slum part
[   15.586974] ata1: SATA max UDMA/133 cmd 0xf8824d00 ctl 0x00000000
bmdma 0x00000000 irq 19
[   15.587093] ata2: SATA max UDMA/133 cmd 0xf8824d80 ctl 0x00000000
bmdma 0x00000000 irq 19
[   15.587211] ata3: SATA max UDMA/133 cmd 0xf8824e00 ctl 0x00000000
bmdma 0x00000000 irq 19
[   15.587331] ata4: SATA max UDMA/133 cmd 0xf8824e80 ctl 0x00000000
bmdma 0x00000000 irq 19
[   15.587394] scsi0 : ahci
[   16.044663] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[   16.089475] ata1.00: ATA-7: HTS541010G9SA00, MBZOC60D, max UDMA/100
[   16.089525] ata1.00: 195371568 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   16.091804] ata1.00: configured for UDMA/100
[   16.091855] scsi1 : ahci
[   16.394567] ata2: SATA link down (SStatus 0 SControl 0)
[   16.394620] scsi2 : ahci
[   16.697494] ata3: SATA link down (SStatus 0 SControl 300)
[   16.697547] scsi3 : ahci
[   17.000422] ata4: SATA link down (SStatus 0 SControl 0)
[   17.000552] scsi 0:0:0:0: Direct-Access     ATA      HTS541010G9SA00 
MBZO PQ: 0 ANSI: 5
[....]
[   18.151756] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[   18.151856] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[   18.151911] sda: Write Protect is off
[   18.151977] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[....]
[   48.143940] ata1.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x2
frozen
[   48.143999] ata1.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0
cdb 0x0 data 4096 in
[   48.144000]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[   48.446854] ata1: soft resetting port
[   48.601835] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[   48.607218] ata1.00: configured for UDMA/100
[   48.607272] ata1: EH complete
[   48.607355] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[   48.607411] sda: Write Protect is off
[   48.607478] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[   78.599605] ata1.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x2
frozen
[   78.599659] ata1.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0
cdb 0x0 data 4096 in
[   78.599661]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[   78.902526] ata1: soft resetting port
[   79.057505] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[   79.062836] ata1.00: configured for UDMA/100
[   79.062887] ata1: EH complete
[   79.062957] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[   79.063011] sda: Write Protect is off
[   79.063077] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[  109.055268] ata1.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x2
frozen
[  109.055324] ata1.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0
cdb 0x0 data 4096 in
[  109.055325]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
[  109.358190] ata1: soft resetting port
[  109.513168] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[  109.518528] ata1.00: configured for UDMA/100
[  109.518579] ata1: EH complete
[  109.518648] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[  109.518703] sda: Write Protect is off
[  109.518769] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[looping forever with this error]

Thanks.
(Please CC me)
-- 
Mathieu Bérard

Re: Regression between 2.6.20 and 2.6.21-rc1: NCQ problem with ahci and Hitachi drive

[Tejun Heo]

Hello, Mathieu.

Mathieu Bérard wrote:
> Hello,
> I have and laptop with an ICH6M SATA Controller and an Hitachi hard drive.
> While it worked well using the ahci module and with NCQ enabled using
> Linux 2.6.20, it does not work anymore (hang at boot) with 2.6.21-rc*
> 
> My drive is among those that were recently blacklisted (see lkml post
> "[PATCH] libata:
> add NCQ blacklist entries from Silicon Image Windowsdriver)
> (Model Number: HTS541010G9SA00 and Firmware Revision: MBZOC60D)
> This blacklisting patch is in -mm now.
> So there is probably a drive related issue here, I'm just wondering why
> it just work
> flawlessly with a 2.6.20...
> 
> Relevant part of kernel log:
> [   16.044663] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> [   16.089475] ata1.00: ATA-7: HTS541010G9SA00, MBZOC60D, max UDMA/100
> [   16.089525] ata1.00: 195371568 sectors, multi 0: LBA48 NCQ (depth 31/32)

No, your drive isn't blacklisted yet.  NCQ is still being enabled.

> [   16.091804] ata1.00: configured for UDMA/100
> [   18.151756] SCSI device sda: write cache: enabled, read cache:
> enabled, doesn't support DPO or FUA
[--snip--]
> [   18.151856] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
> [   18.151911] sda: Write Protect is off
> [   18.151977] SCSI device sda: write cache: enabled, read cache:
> enabled, doesn't support DPO or FUA
> [....]
> [   48.143940] ata1.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x2
> frozen
> [   48.143999] ata1.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0
> cdb 0x0 data 4096 in
> [   48.144000]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
> 0x4 (timeout)

It looks like IRQ isn't getting through.  Does giving "acpi=off" kernel
parameter make any difference?

-- 
tejun

Re: Regression between 2.6.20 and 2.6.21-rc1: NCQ problem with ahci and Hitachi drive

[Mathieu Bérard]

Tejun Heo a écrit :

Hi,
> No, your drive isn't blacklisted yet.  NCQ is still being enabled.
>
>   
Sorry, I wasn't very clear: The NCQ blacklist patch is not in
the 2.6.21-rc tree, just in -mm. I tried a 2.6.21-rc2-mm1 and
the drive is blacklisted. The logs I pasted were from 2.6.20 and
2.6.21-rc1.
>> [   16.091804] ata1.00: configured for UDMA/100
>> [   18.151756] SCSI device sda: write cache: enabled, read cache:
>> enabled, doesn't support DPO or FUA
>>     
> [--snip--]
>   
>> [   18.151856] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
>> [   18.151911] sda: Write Protect is off
>> [   18.151977] SCSI device sda: write cache: enabled, read cache:
>> enabled, doesn't support DPO or FUA
>> [....]
>> [   48.143940] ata1.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x2
>> frozen
>> [   48.143999] ata1.00: cmd 60/08:00:00:00:00/00:00:00:00:00/40 tag 0
>> cdb 0x0 data 4096 in
>> [   48.144000]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
>> 0x4 (timeout)
>>     
>
> It looks like IRQ isn't getting through.  Does giving "acpi=off" kernel
> parameter make any difference?
>
>   

Yes It works with acpi=off (2.6.21-rc1):
Please notice that IRQ is changed from 19 with ACPI to 11 without.

[   24.226291] SCSI subsystem initialized
[   24.230178] libata version 2.10 loaded.
[   24.231315] ahci 0000:00:1f.2: version 2.0
[   25.231137] PCI: Setting latency timer of device 0000:00:1f.2 to 64
[   25.231144] ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 4 ports 1.5
Gbps 0x5 impl SATA mode
[   25.231202] ahci 0000:00:1f.2: flags: 64bit ncq pm led slum part
[   25.231341] ata1: SATA max UDMA/133 cmd 0xf880ed00 ctl 0x00000000
bmdma 0x00000000 irq 11
[   25.231468] ata2: SATA max UDMA/133 cmd 0xf880ed80 ctl 0x00000000
bmdma 0x00000000 irq 11
[   25.231596] ata3: SATA max UDMA/133 cmd 0xf880ee00 ctl 0x00000000
bmdma 0x00000000 irq 11
[   25.231722] ata4: SATA max UDMA/133 cmd 0xf880ee80 ctl 0x00000000
bmdma 0x00000000 irq 11
[   25.231783] scsi0 : ahci
[   25.688849] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[   25.689915] ata1.00: ATA-7: HTS541010G9SA00, MBZOC60D, max UDMA/100
[   25.689964] ata1.00: 195371568 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   25.691271] ata1.00: configured for UDMA/100
[   25.691321] scsi1 : ahci
[   25.993653] ata2: SATA link down (SStatus 0 SControl 0)
[   25.993706] scsi2 : ahci
[   26.296471] ata3: SATA link down (SStatus 0 SControl 300)
[   26.296524] scsi3 : ahci
[   26.599288] ata4: SATA link down (SStatus 0 SControl 0)
[   26.599423] scsi 0:0:0:0: Direct-Access     ATA      HTS541010G9SA00 
MBZO PQ: 0 ANSI: 5
[....]
[   27.741608] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[   27.741706] sda: Write Protect is off
[   27.741753] sda: Mode Sense: 00 3a 00 00
[   27.741921] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[   27.742037] SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
[   27.742091] sda: Write Protect is off
[   27.742171] sda: Mode Sense: 00 3a 00 00
[   27.742182] SCSI device sda: write cache: enabled, read cache:
enabled, doesn't support DPO or FUA
[   27.742238]  sda: sda1 sda2 < sda5 sda6 > sda3
[   28.204850] sd 0:0:0:0: Attached scsi disk sda
[   28.207809] sd 0:0:0:0: Attached scsi generic sg0 type 0


-- 
Mathieu

Re: Regression between 2.6.20 and 2.6.21-rc1: NCQ problem with ahci and Hitachi drive

[Len Brown]

> Yes It works with acpi=off (2.6.21-rc1):
> Please notice that IRQ is changed from 19 with ACPI to 11 without.

Please verify the problem still exists in the latest 2.6.21 git.

If yes, please file a bug here:
http://bugzilla.kernel.org/enter_bug.cgi?product=ACPI

For 2.6.20.stable, please attach
the complete output from dmesg -s64000
output from acpidump
output from lspci -vv
and paste a copy of /proc/interrupts

For 2.6.21.broken, please attach as much
of the dmesg as you can capture, and the /proc/interrupts
if you can get that far.

thanks,
-Len