libata badness

libata badness

[William Knop]

Hi all,

I'm running a raid5 array atop a few sata drives via a promise tx4 
controller. The kernel is the official fedora lk 2.6.8-1, although I had 
run a few different kernels (never entirely successfully) with this array 
in the past.

In fact, this past weekend, I was getting oopses and panics (on lk 
2.6.8.1, 2.6.9-rc3, 2.6.9-rc3-mm1, and 2.6.9-rc3 w/ Jeff Garzik's recent 
libata patches) all of which happened when rebuilding a spare drive in the 
array. Unfortunately, somehow my root filesystem (ext3) got blown away-- 
it was on a reliable scsi drive (no bad blocks; I checked afterwards), and 
an adaptec aic7xxx host. The ram was good; I ran memtest86 on it. I'm 
assuming this was caused by some major kernel corruption, originating from 
libata.

I have since rebuilt my computer using an AMD Sempron (basically a Duron) 
rather than a P4. Other than that (cpu + m/b), it's the same hardware.

The errors I got over the weekend are similar to the one I just captured 
on my fresh fc2/lk2.6.8-1 install (at the same point; the spare disk had 
begun rebuilding). It's attached below.

Anyway, I haven't been able to find any other reports of this, so I'm at a 
loss about what to do. I hesitate to bring my array up at all now, for 
fear of blowing it away. Any assistance would be greatly appriciated.

Thanks much,
Will


---------- SNIP ----------
Unable to handle kernel paging request at virtual address 01000004
  printing eip:
229e4d8c
*pde = 00000000
Oops: 0000 [#1]
Modules linked in: raid5 xor sata_promise md5 ipv6 parport_pc lp parport 
autofs4 sunrpc sk98lin sg joydev dm_mod uhci_hcd ehci_hcd button battery 
asus_acpi ac ext3 jbd sata_via libata aic7xxx sd_mod scsi_mod
CPU:    0
EIP:    0060:[<229e4d8c>]    Not tainted
EFLAGS: 00010206   (2.6.8-1.521)
EIP is at handle_stripe+0x29a/0x1407 [raid5]
eax: 00000001   ebx: 00000000   ecx: 00915cb8   edx: 21f7e1c0
esi: 1ccbd118   edi: 21f7e1c0   ebp: 01000000   esp: 1d300f28
ds: 007b   es: 007b   ss: 0068
Process md0_raid5 (pid: 2626, threadinfo=1d300000 task=1d317970)
Stack: 2283eb57 20db8000 21f7e1c0 21c30288 1ccbd204 20db8000 00000001 
1ccbd158
        00000002 00000000 00000000 00000001 00000000 00000000 00000001 
00000000
        00000001 00000001 00000000 00000003 1ccbd0ac 21f7e1c0 1ccbd0ac 
21f76c00
Call Trace:
  [<2283eb57>] ata_scsi_queuecmd+0xbe/0xc7 [libata]
  [<229e6b1c>] raid5d+0x1ce/0x2f8 [raid5]
  [<0228f5d2>] md_thread+0x227/0x256
  [<0211be05>] autoremove_wake_function+0x0/0x2d
  [<0211be05>] autoremove_wake_function+0x0/0x2d
  [<0228f3ab>] md_thread+0x0/0x256
  [<021041d9>] kernel_thread_helper+0x5/0xb
Code: 8b 55 04 83 c1 08 8b 45 00 83 d3 00 39 da 72 0e 0f 87 e0 01
---------- SNIP ----------

Re: libata badness

[Jon Lewis]

On Mon, 4 Oct 2004, William Knop wrote:

> Hi all,
>
> I'm running a raid5 array atop a few sata drives via a promise tx4
> controller. The kernel is the official fedora lk 2.6.8-1, although I had
> run a few different kernels (never entirely successfully) with this array
> in the past.

What kind of sata drives?  It's not quite the same end result, but there
have been several posts on linux-raid about defective Maxtor sata drives
causing system freezes.  If your drives are Maxtor, download their
powermax utility and test your drives.  You may find that you have one or
more marginal drives that appear to work most of the time, but powermax
will determine are bad.  Replacing one like that fixed my problems.

----------------------------------------------------------------------
 Jon Lewis                   |  I route
 Senior Network Engineer     |  therefore you are
 Atlantic Net                |
_________ http://www.lewis.org/~jlewis/pgp for PGP public key_________

Re: libata badness

[William Knop]

> What kind of sata drives?  It's not quite the same end result, but there
> have been several posts on linux-raid about defective Maxtor sata drives
> causing system freezes.  If your drives are Maxtor, download their
> powermax utility and test your drives.  You may find that you have one or
> more marginal drives that appear to work most of the time, but powermax
> will determine are bad.  Replacing one like that fixed my problems.

Ah, well all of them are Maxtor drives... One 6y250m0 and three 7y250m0 
drives. I'm using powermax on them right now. They all passed the quick 
test, and the full test results are forthcoming.

Actually, I was backing up the array (cp from the array - 2 of 3 drives 
running - to a normal drive) when I read your response. Shortly 
thereafter, during the cp (perhaps after copying 100GB-120GB), I got a 
double fault. I've never gotten a double fault before, but I'm guessing 
it's quite a serious error. It totally locked up the machine, and it 
outputted two lines each with a double fault message, followed by a 
register dump.

The saga continues...

Will

Re: libata badness

[Mark Lord]

I have used Maxtor "SATA" drives that require
the O/S to do a "SET FEATURES :: UDMA_MODE" command
on them before they will operate reliably.
This despite the SATA spec stating clearly that
such a command should/will have no effect.

I suppose libata does this already, but just in case not..
Something simple to check up on.
-- 
Mark Lord
(hdparm keeper & the original "Linux IDE Guy")

William Knop wrote:
>
> Ah, well all of them are Maxtor drives... One 6y250m0 and three 7y250m0 
> drives. I'm using powermax on them right now. They all passed the quick 
> test, and the full test results are forthcoming.

Re: libata badness

[Jon Lewis]

On Mon, 4 Oct 2004, William Knop wrote:

> Ah, well all of them are Maxtor drives... One 6y250m0 and three 7y250m0
> drives. I'm using powermax on them right now. They all passed the quick
> test, and the full test results are forthcoming.

I'm pretty sure all the bad ones we had (at least the one I found at my
location) "failed" the quick test in that after the quick test it asked me
to run the full test, after which it spit out the magic fault code to give
Maxtor's RMA form.  Another possibility that comes to mind is that your
power supply could be inadequate to run the system and all the drives.

----------------------------------------------------------------------
 Jon Lewis                   |  I route
 Senior Network Engineer     |  therefore you are
 Atlantic Net                |
_________ http://www.lewis.org/~jlewis/pgp for PGP public key_________

Re: libata badness

[William Knop]

Great. I'll give that a shot after I drive checker utility finishes.

However it seems like the kernel shouldn't be oopsing, panicking, or 
double faulting if the drive is questionable. It apparently blew away my 
root fs last time. A peripheral drive failure shouldn't cause such 
destruction across the system, no?

On Mon, 4 Oct 2004, Mark Lord wrote:

> I have used Maxtor "SATA" drives that require
> the O/S to do a "SET FEATURES :: UDMA_MODE" command
> on them before they will operate reliably.
> This despite the SATA spec stating clearly that
> such a command should/will have no effect.
>
> I suppose libata does this already, but just in case not..
> Something simple to check up on.
> -- 
> Mark Lord
> (hdparm keeper & the original "Linux IDE Guy")
>
> William Knop wrote:
>> 
>> Ah, well all of them are Maxtor drives... One 6y250m0 and three 7y250m0 
>> drives. I'm using powermax on them right now. They all passed the quick 
>> test, and the full test results are forthcoming.
>
>

Re: libata badness

[Jeff Garzik]

William Knop wrote:
> Hi all,
> 
> I'm running a raid5 array atop a few sata drives via a promise tx4 
> controller. The kernel is the official fedora lk 2.6.8-1, although I had 
> run a few different kernels (never entirely successfully) with this 
> array in the past.
> 
> In fact, this past weekend, I was getting oopses and panics (on lk 
> 2.6.8.1, 2.6.9-rc3, 2.6.9-rc3-mm1, and 2.6.9-rc3 w/ Jeff Garzik's recent 
> libata patches) all of which happened when rebuilding a spare drive in 
> the array. Unfortunately, somehow my root filesystem (ext3) got blown 
> away-- it was on a reliable scsi drive (no bad blocks; I checked 
> afterwards), and an adaptec aic7xxx host. The ram was good; I ran 
> memtest86 on it. I'm assuming this was caused by some major kernel 
> corruption, originating from libata.
> 
> I have since rebuilt my computer using an AMD Sempron (basically a 
> Duron) rather than a P4. Other than that (cpu + m/b), it's the same 
> hardware.
> 
> The errors I got over the weekend are similar to the one I just captured 
> on my fresh fc2/lk2.6.8-1 install (at the same point; the spare disk had 
> begun rebuilding). It's attached below.
> 
> Anyway, I haven't been able to find any other reports of this, so I'm at 
> a loss about what to do. I hesitate to bring my array up at all now, for 
> fear of blowing it away. Any assistance would be greatly appriciated.
> 
> Thanks much,
> Will
> 
> 
> ---------- SNIP ----------
> Unable to handle kernel paging request at virtual address 01000004
>  printing eip:
> 229e4d8c
> *pde = 00000000
> Oops: 0000 [#1]
> Modules linked in: raid5 xor sata_promise md5 ipv6 parport_pc lp parport 
> autofs4 sunrpc sk98lin sg joydev dm_mod uhci_hcd ehci_hcd button battery 
> asus_acpi ac ext3 jbd sata_via libata aic7xxx sd_mod scsi_mod
> CPU:    0
> EIP:    0060:[<229e4d8c>]    Not tainted
> EFLAGS: 00010206   (2.6.8-1.521)
> EIP is at handle_stripe+0x29a/0x1407 [raid5]
> eax: 00000001   ebx: 00000000   ecx: 00915cb8   edx: 21f7e1c0
> esi: 1ccbd118   edi: 21f7e1c0   ebp: 01000000   esp: 1d300f28
> ds: 007b   es: 007b   ss: 0068
> Process md0_raid5 (pid: 2626, threadinfo=1d300000 task=1d317970)
> Stack: 2283eb57 20db8000 21f7e1c0 21c30288 1ccbd204 20db8000 00000001 
> 1ccbd158
>        00000002 00000000 00000000 00000001 00000000 00000000 00000001 
> 00000000
>        00000001 00000001 00000000 00000003 1ccbd0ac 21f7e1c0 1ccbd0ac 
> 21f76c00
> Call Trace:
>  [<2283eb57>] ata_scsi_queuecmd+0xbe/0xc7 [libata]
>  [<229e6b1c>] raid5d+0x1ce/0x2f8 [raid5]
>  [<0228f5d2>] md_thread+0x227/0x256
>  [<0211be05>] autoremove_wake_function+0x0/0x2d
>  [<0211be05>] autoremove_wake_function+0x0/0x2d
>  [<0228f3ab>] md_thread+0x0/0x256
>  [<021041d9>] kernel_thread_helper+0x5/0xb
> Code: 8b 55 04 83 c1 08 8b 45 00 83 d3 00 39 da 72 0e 0f 87 e0 01

It either smells like a hardware problem or a raid problem.  The oops 
you list here is in raid5 not libata.

	Jeff

Re: libata badness

[Jeff Garzik]

Mark Lord wrote:
> I have used Maxtor "SATA" drives that require
> the O/S to do a "SET FEATURES :: UDMA_MODE" command
> on them before they will operate reliably.
> This despite the SATA spec stating clearly that
> such a command should/will have no effect.
> 
> I suppose libata does this already, but just in case not..
> Something simple to check up on.

libata always issues SET FEATURES - XFER MODE.

	Jeff

Re: libata badness

[William Knop]

> Maxtor's RMA form.  Another possibility that comes to mind is that your
> power supply could be inadequate to run the system and all the drives.

The power supply on this box is something upwards of 450W. Right now I 
only have four 7200rpm sata drives along with my athalon mb/cpu and a 
couple fans. I had six 7200rpm drives connected w/o raid and a P4 before 
and I had no problems. I'm pretty sure this isn't due to insufficient 
power supply.

Re: libata badness

[William Knop]

> It either smells like a hardware problem or a raid problem.  The oops you 
> list here is in raid5 not libata.

I'm inclined to agree. I should have titled the thread "libata/md badness" 
since it appears to be a raid atop sata issue. Raid5 apparently works over 
scsi, though.

This is really beyond my realm of knowledge, though. After I check my 
drives for errors, I'm going to back up my array and then experiment a 
bit. I'll post any oopses I find in hopes that someone will be able to 
properly interpret them.

Will

Re: libata badness

[William Knop]

I just got another oops while trying to cp from my md/raid5 array (2 of 3 
sata drives) to another sata drive on the same controller. This time, 
though, it said there's a bug in timer.c, line 405, and that the 
stack's garbage. I'm thinking it has nothing to do with timer.c, and 
something in md or libata is chomping all over the kernel.

It's odd that no one else is experiencing problems. I read a post where 
someone was sucessfully using a mandrake 2.6.8.1 kernel, with the same 
controller (promise tx4) and raid5. I suppose my controller card could be 
faulty, but it's odd that drives on the controller w/o raid seem to be 
doing alright.

I'm going to try a 2.4 kernel so I might be able to back up my array 
before things get really hairy. I should probably also ping Neil Brown or 
whoever the current md maintainer is. I'll continue to post findings.

Will

Re: libata badness

[Jim Paris]

> I just got another oops while trying to cp from my md/raid5 array (2 of 3 
> sata drives) to another sata drive on the same controller. This time, 
> though, it said there's a bug in timer.c, line 405, and that the 
> stack's garbage. I'm thinking it has nothing to do with timer.c, and 
> something in md or libata is chomping all over the kernel.

Or else something else on your system is bad.  Like your CPU or RAM.
Run memtest for a while.

-jim

Re: libata badness

[Jeff Garzik]

William Knop wrote:
> 
> I just got another oops while trying to cp from my md/raid5 array (2 of 
> 3 sata drives) to another sata drive on the same controller. This time, 
> though, it said there's a bug in timer.c, line 405, and that the stack's 
> garbage. I'm thinking it has nothing to do with timer.c, and something 
> in md or libata is chomping all over the kernel.

If you are getting random oopses all over the place, I would suspect 
hardware before I suspect buggy code.

Jim's, and others' suggestions were good:  check power connectors (not 
just overall power consumption), test CPU, RAM, temperature, ...

	Jeff

Re: libata badness

[William Knop]

> Or else something else on your system is bad.  Like your CPU or RAM.
> Run memtest for a while.

I ran memtest for a few hours. It all checks out. Also, CPU intensive 
stuff doesn't cause weirdness.

The only things which cause corruption, so far as I can tell, are 
operations on my raid device, md0. Copying from the array takes a while 
for a crash, while rebuilding a drive on the array is very prompt (<1m) at 
causing a crash. The crashes likely as not cause widespread kernel 
corruption. It's only a matter of time before my root fs is blown away 
again.

Re: libata badness

[Neil Brown]

On Monday October 4, wknop@andrew.cmu.edu wrote:
> CPU:    0
> EIP:    0060:[<229e4d8c>]    Not tainted
> EFLAGS: 00010206   (2.6.8-1.521)
> EIP is at handle_stripe+0x29a/0x1407 [raid5]
> eax: 00000001   ebx: 00000000   ecx: 00915cb8   edx: 21f7e1c0
> esi: 1ccbd118   edi: 21f7e1c0   ebp: 01000000   esp: 1d300f28
> ds: 007b   es: 007b   ss: 0068
> Process md0_raid5 (pid: 2626, threadinfo=1d300000 task=1d317970)
> Stack: 2283eb57 20db8000 21f7e1c0 21c30288 1ccbd204 20db8000 00000001 
> 1ccbd158
>         00000002 00000000 00000000 00000001 00000000 00000000 00000001 
> 00000000
>         00000001 00000001 00000000 00000003 1ccbd0ac 21f7e1c0 1ccbd0ac 
> 21f76c00
> Call Trace:
>   [<2283eb57>] ata_scsi_queuecmd+0xbe/0xc7 [libata]
>   [<229e6b1c>] raid5d+0x1ce/0x2f8 [raid5]
>   [<0228f5d2>] md_thread+0x227/0x256
>   [<0211be05>] autoremove_wake_function+0x0/0x2d
>   [<0211be05>] autoremove_wake_function+0x0/0x2d
>   [<0228f3ab>] md_thread+0x0/0x256
>   [<021041d9>] kernel_thread_helper+0x5/0xb
> Code: 8b 55 04 83 c1 08 8b 45 00 83 d3 00 39 da 72 0e 0f 87 e0 01

This code starts:

   0:   8b 55 04                  mov    0x4(%ebp),%edx
   3:   83 c1 08                  add    $0x8,%ecx

and as %ebp is 01000000, this oopses.  
It looks very much like a single-bit memory error (as has already been
suggested as a possibility).

NeilBrown

Re: libata badness

[William Knop]

> This code starts:
>
>   0:   8b 55 04                  mov    0x4(%ebp),%edx
>   3:   83 c1 08                  add    $0x8,%ecx
>
> and as %ebp is 01000000, this oopses.
> It looks very much like a single-bit memory error (as has already been
> suggested as a possibility).

Oh my. So, I ran memcheck again for a few hours, and it checked out fine. 
Just in case, though, I bought a replacement stick of ram. Well, the 
oopses went away, so it must have been the ram.

Sigh. Sorry about that, everyone. I suppose the raid operations are 
particularly memory intensive. Anyway, thanks a ton for all the help.

Will

Re: libata badness

[Brad Campbell]

William Knop wrote:
> 
>> This code starts:
>>
>>   0:   8b 55 04                  mov    0x4(%ebp),%edx
>>   3:   83 c1 08                  add    $0x8,%ecx
>>
>> and as %ebp is 01000000, this oopses.
>> It looks very much like a single-bit memory error (as has already been
>> suggested as a possibility).
> 
> 
> Oh my. So, I ran memcheck again for a few hours, and it checked out 
> fine. Just in case, though, I bought a replacement stick of ram. Well, 
> the oopses went away, so it must have been the ram.

For future reference, I have had errors show up after 24-36 hours of memtest86. I usually find that 
if it passes 48 hours of testing then things are looking pretty reliable. A couple of hours is 
usually too small a sample to rely on.

Brad

libata badness

[Kumar Gala]

I'm getting the following badness with top of tree on a embedded  
PowerPC w/a ULI 1575 bridge (M5229 IDE):

02:1f.0 IDE interface: Acer Laboratories Inc. [ALi] M5229 IDE (rev c8)

If you need more info let me know.

- k

ahci 0000:02:1f.1: AHCI 0001.0000 32 slots 4 ports 3 Gbps 0xf impl  
SATA mode
ahci 0000:02:1f.1: flags: ncq sntf ilck pm led clo pmp pio slum part
------------[ cut here ]------------
Badness at c021e700 [verbose debug info unavailable]
NIP: c021e700 LR: c021e6e8 CTR: c022ce90
REGS: ef82bca0 TRAP: 0700   Not tainted  (2.6.27-rc1-00495-g33bd9fe- 
dirty)
MSR: 00029032 <EE,ME,IR,DR>  CR: 22044022  XER: 20000000
TASK = ef830000[1] 'swapper' THREAD: ef82a000 CPU: 1
GPR00: 00000001 ef82bd50 ef830000 00000000 00009032 00000000 ef0b64fc  
00000000
GPR08: ef937c10 c022f93f efbfc8e0 ef900b60 22044028 fffdd3ff 0ffe8700  
c044c17c
GPR16: c04d52ec ef82f458 ef82f4f4 ef82f4f4 c044c234 c044c5d8 c044c5d8  
c044c220
GPR24: c044c218 c04d52f0 00000080 c022f940 00000000 c044c244 efbec490  
00000000
NIP [c021e700] ata_host_activate+0x40/0x10c
LR [c021e6e8] ata_host_activate+0x28/0x10c
Call Trace:
[ef82bd50] [c021e6e8] ata_host_activate+0x28/0x10c (unreliable)
[ef82bd80] [c022f48c] ahci_init_one+0x8b4/0xd68
[ef82be30] [c01b69c0] pci_device_probe+0x84/0xa8
[ef82be50] [c01e5438] driver_probe_device+0xb4/0x1e8
[ef82be70] [c01e55f0] __driver_attach+0x84/0x88
[ef82be90] [c01e4ba0] bus_for_each_dev+0x5c/0xa4
[ef82bec0] [c01e5254] driver_attach+0x24/0x34
[ef82bed0] [c01e44b8] bus_add_driver+0x1d8/0x24c
[ef82bef0] [c01e5810] driver_register+0x70/0x160
[ef82bf10] [c01b6c54] __pci_register_driver+0x64/0xc4
[ef82bf30] [c04aaa60] ahci_init+0x28/0x38
[ef82bf40] [c048717c] do_one_initcall+0x38/0x1ac
[ef82bfb0] [c04874e0] kernel_init+0x1f0/0x1fc
[ef82bff0] [c0013b04] kernel_thread+0x44/0x60
Instruction dump:
7cbb2b78 90010034 7cda3378 7cf93b78 7c7e1b78 4bff9dbd 7c7f1b79 408200c8
2f9c0000 409e002c 313bffff 7c09d910 <0f000000> 80010034 7fc3f378  
7f24cb78
scsi0 : ahci
scsi1 : ahci
scsi2 : ahci
scsi3 : ahci
ata1: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006100
ata2: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006180
ata3: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006200
ata4: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006280
ata1: SATA link down (SStatus 0 SControl 300)
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata2.00: qc timeout (cmd 0xec)
ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata2.00: qc timeout (cmd 0xec)
ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata2.00: qc timeout (cmd 0xec)
ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata3: SATA link down (SStatus 0 SControl 300)
ata4: SATA link down (SStatus 0 SControl 300)
scsi4 : pata_ali
scsi5 : pata_ali
ata5: PATA max UDMA/133 cmd 0x1200 ctl 0x1208 bmdma 0x1220
ata6: PATA max UDMA/133 cmd 0x1210 ctl 0x1218 bmdma 0x1228
ata5.00: ATAPI: TSSTcorp CDW/DVD SH-M522C, TS06, max UDMA/33
ata5.00: WARNING: ATAPI DMA disabled for reliablity issues.  It can be  
enabled
ata5.00: WARNING: via pata_ali.atapi_dma modparam or corresponding  
sysfs node.
ata5.00: configured for UDMA/33
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for UDMA/33
ata5: EH complete
ata5.00: limiting speed to UDMA/25:PIO4
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for UDMA/25
ata5: EH complete
ata5.00: limiting speed to PIO4
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO4
ata5: EH complete
ata5.00: limiting speed to PIO3
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO3
ata5: EH complete
ata5.00: limiting speed to PIO0
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: status: { DRDY }
ata5: soft resetting link
ata5.00: configured for PIO0
ata5: EH complete
ata5: WARNING: synchronous SCSI scan failed without making any progress,
                   switching to async

Re: libata badness

[Ben Dooks]

On Thu, Jul 31, 2008 at 01:53:45PM -0500, Kumar Gala wrote:
> I'm getting the following badness with top of tree on a embedded  
> PowerPC w/a ULI 1575 bridge (M5229 IDE):
> 
> 02:1f.0 IDE interface: Acer Laboratories Inc. [ALi] M5229 IDE (rev c8)
> 
> If you need more info let me know.
> 
> - k
> 
> ahci 0000:02:1f.1: AHCI 0001.0000 32 slots 4 ports 3 Gbps 0xf impl  
> SATA mode
> ahci 0000:02:1f.1: flags: ncq sntf ilck pm led clo pmp pio slum part
> ------------[ cut here ]------------
> Badness at c021e700 [verbose debug info unavailable]

it would be helpful to compile a kernel with verbose fault information
turned on.

> NIP: c021e700 LR: c021e6e8 CTR: c022ce90
> REGS: ef82bca0 TRAP: 0700   Not tainted  (2.6.27-rc1-00495-g33bd9fe- 
> dirty)
> MSR: 00029032 <EE,ME,IR,DR>  CR: 22044022  XER: 20000000
> TASK = ef830000[1] 'swapper' THREAD: ef82a000 CPU: 1
> GPR00: 00000001 ef82bd50 ef830000 00000000 00009032 00000000 ef0b64fc  
> 00000000
> GPR08: ef937c10 c022f93f efbfc8e0 ef900b60 22044028 fffdd3ff 0ffe8700  
> c044c17c
> GPR16: c04d52ec ef82f458 ef82f4f4 ef82f4f4 c044c234 c044c5d8 c044c5d8  
> c044c220
> GPR24: c044c218 c04d52f0 00000080 c022f940 00000000 c044c244 efbec490  
> 00000000
> NIP [c021e700] ata_host_activate+0x40/0x10c
> LR [c021e6e8] ata_host_activate+0x28/0x10c
> Call Trace:
> [ef82bd50] [c021e6e8] ata_host_activate+0x28/0x10c (unreliable)
> [ef82bd80] [c022f48c] ahci_init_one+0x8b4/0xd68
> [ef82be30] [c01b69c0] pci_device_probe+0x84/0xa8
> [ef82be50] [c01e5438] driver_probe_device+0xb4/0x1e8
> [ef82be70] [c01e55f0] __driver_attach+0x84/0x88
> [ef82be90] [c01e4ba0] bus_for_each_dev+0x5c/0xa4
> [ef82bec0] [c01e5254] driver_attach+0x24/0x34
> [ef82bed0] [c01e44b8] bus_add_driver+0x1d8/0x24c
> [ef82bef0] [c01e5810] driver_register+0x70/0x160
> [ef82bf10] [c01b6c54] __pci_register_driver+0x64/0xc4
> [ef82bf30] [c04aaa60] ahci_init+0x28/0x38
> [ef82bf40] [c048717c] do_one_initcall+0x38/0x1ac
> [ef82bfb0] [c04874e0] kernel_init+0x1f0/0x1fc
> [ef82bff0] [c0013b04] kernel_thread+0x44/0x60
> Instruction dump:
> 7cbb2b78 90010034 7cda3378 7cf93b78 7c7e1b78 4bff9dbd 7c7f1b79 408200c8
> 2f9c0000 409e002c 313bffff 7c09d910 <0f000000> 80010034 7fc3f378  
> 7f24cb78
> scsi0 : ahci
> scsi1 : ahci
> scsi2 : ahci
> scsi3 : ahci
> ata1: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006100
> ata2: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006180
> ata3: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006200
> ata4: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006280
> ata1: SATA link down (SStatus 0 SControl 300)
> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> ata2.00: qc timeout (cmd 0xec)
> ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> ata2.00: qc timeout (cmd 0xec)
> ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> ata2.00: qc timeout (cmd 0xec)
> ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> ata3: SATA link down (SStatus 0 SControl 300)
> ata4: SATA link down (SStatus 0 SControl 300)
> scsi4 : pata_ali
> scsi5 : pata_ali
> ata5: PATA max UDMA/133 cmd 0x1200 ctl 0x1208 bmdma 0x1220
> ata6: PATA max UDMA/133 cmd 0x1210 ctl 0x1218 bmdma 0x1228

Looks like you're running into the same problem as I did, with the
fact that the M5529 is in native mode, but doesn't have any IRQ
available. Do you know if the bridge chip in it is in routes the
IRQs internally?

> ata5.00: ATAPI: TSSTcorp CDW/DVD SH-M522C, TS06, max UDMA/33
> ata5.00: WARNING: ATAPI DMA disabled for reliablity issues.  It can be  
> enabled
> ata5.00: WARNING: via pata_ali.atapi_dma modparam or corresponding  
> sysfs node.
> ata5.00: configured for UDMA/33
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for UDMA/33
> ata5: EH complete
> ata5.00: limiting speed to UDMA/25:PIO4
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for UDMA/25
> ata5: EH complete
> ata5.00: limiting speed to PIO4
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO4
> ata5: EH complete
> ata5.00: limiting speed to PIO3
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO3
> ata5: EH complete
> ata5.00: limiting speed to PIO0
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> ata5.00: cmd a0/00:00:00:24:00/00:00:00:00:00/a0 tag 0 pio 36 in
>          cdb 12 00 00 00 24 00 00 00  00 00 00 00 00 00 00 00
>          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> ata5.00: status: { DRDY }
> ata5: soft resetting link
> ata5.00: configured for PIO0
> ata5: EH complete
> ata5: WARNING: synchronous SCSI scan failed without making any progress,
>                   switching to async
> 
> --
> 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

-- 
-- 
Ben

Q:      What's a light-year?
A:      One-third less calories than a regular year.

Re: libata badness

[Kumar Gala]

On Jul 31, 2008, at 2:02 PM, Ben Dooks wrote:

> On Thu, Jul 31, 2008 at 01:53:45PM -0500, Kumar Gala wrote:
>> I'm getting the following badness with top of tree on a embedded
>> PowerPC w/a ULI 1575 bridge (M5229 IDE):
>>
>> 02:1f.0 IDE interface: Acer Laboratories Inc. [ALi] M5229 IDE (rev  
>> c8)
>>
>> If you need more info let me know.
>>
>> - k
>>
>> ahci 0000:02:1f.1: AHCI 0001.0000 32 slots 4 ports 3 Gbps 0xf impl
>> SATA mode
>> ahci 0000:02:1f.1: flags: ncq sntf ilck pm led clo pmp pio slum part
>> ------------[ cut here ]------------
>> Badness at c021e700 [verbose debug info unavailable]
>
> it would be helpful to compile a kernel with verbose fault information
> turned on.

Doesn't seem to provide too much more info on ppc.  just says the file/ 
line number of the badness.

>> NIP: c021e700 LR: c021e6e8 CTR: c022ce90
>> REGS: ef82bca0 TRAP: 0700   Not tainted  (2.6.27-rc1-00495-g33bd9fe-
>> dirty)
>> MSR: 00029032 <EE,ME,IR,DR>  CR: 22044022  XER: 20000000
>> TASK = ef830000[1] 'swapper' THREAD: ef82a000 CPU: 1
>> GPR00: 00000001 ef82bd50 ef830000 00000000 00009032 00000000 ef0b64fc
>> 00000000
>> GPR08: ef937c10 c022f93f efbfc8e0 ef900b60 22044028 fffdd3ff 0ffe8700
>> c044c17c
>> GPR16: c04d52ec ef82f458 ef82f4f4 ef82f4f4 c044c234 c044c5d8 c044c5d8
>> c044c220
>> GPR24: c044c218 c04d52f0 00000080 c022f940 00000000 c044c244 efbec490
>> 00000000
>> NIP [c021e700] ata_host_activate+0x40/0x10c
>> LR [c021e6e8] ata_host_activate+0x28/0x10c
>> Call Trace:
>> [ef82bd50] [c021e6e8] ata_host_activate+0x28/0x10c (unreliable)
>> [ef82bd80] [c022f48c] ahci_init_one+0x8b4/0xd68
>> [ef82be30] [c01b69c0] pci_device_probe+0x84/0xa8
>> [ef82be50] [c01e5438] driver_probe_device+0xb4/0x1e8
>> [ef82be70] [c01e55f0] __driver_attach+0x84/0x88
>> [ef82be90] [c01e4ba0] bus_for_each_dev+0x5c/0xa4
>> [ef82bec0] [c01e5254] driver_attach+0x24/0x34
>> [ef82bed0] [c01e44b8] bus_add_driver+0x1d8/0x24c
>> [ef82bef0] [c01e5810] driver_register+0x70/0x160
>> [ef82bf10] [c01b6c54] __pci_register_driver+0x64/0xc4
>> [ef82bf30] [c04aaa60] ahci_init+0x28/0x38
>> [ef82bf40] [c048717c] do_one_initcall+0x38/0x1ac
>> [ef82bfb0] [c04874e0] kernel_init+0x1f0/0x1fc
>> [ef82bff0] [c0013b04] kernel_thread+0x44/0x60
>> Instruction dump:
>> 7cbb2b78 90010034 7cda3378 7cf93b78 7c7e1b78 4bff9dbd 7c7f1b79  
>> 408200c8
>> 2f9c0000 409e002c 313bffff 7c09d910 <0f000000> 80010034 7fc3f378
>> 7f24cb78
>> scsi0 : ahci
>> scsi1 : ahci
>> scsi2 : ahci
>> scsi3 : ahci
>> ata1: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006100
>> ata2: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006180
>> ata3: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006200
>> ata4: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006280
>> ata1: SATA link down (SStatus 0 SControl 300)
>> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
>> ata2.00: qc timeout (cmd 0xec)
>> ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
>> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
>> ata2.00: qc timeout (cmd 0xec)
>> ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
>> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
>> ata2.00: qc timeout (cmd 0xec)
>> ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
>> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
>> ata3: SATA link down (SStatus 0 SControl 300)
>> ata4: SATA link down (SStatus 0 SControl 300)
>> scsi4 : pata_ali
>> scsi5 : pata_ali
>> ata5: PATA max UDMA/133 cmd 0x1200 ctl 0x1208 bmdma 0x1220
>> ata6: PATA max UDMA/133 cmd 0x1210 ctl 0x1218 bmdma 0x1228
>
> Looks like you're running into the same problem as I did, with the
> fact that the M5529 is in native mode, but doesn't have any IRQ
> available. Do you know if the bridge chip in it is in routes the
> IRQs internally?

They are routed via an i8259 in the bridge.

- k

Re: libata badness

[Scott Wood]

On Thu, Jul 31, 2008 at 03:24:31PM -0500, Kumar Gala wrote:
> >it would be helpful to compile a kernel with verbose fault information
> >turned on.
> 
> Doesn't seem to provide too much more info on ppc.

I'm pretty sure it does the same thing on ppc as on all the other
architectures.

> just says the file/ line number of the badness.

...which is a lot more useful than an address in someone else's kernel
image.

-Scott

Re: libata badness

[Anton Vorontsov]

On Thu, Jul 31, 2008 at 01:53:45PM -0500, Kumar Gala wrote:
> I'm getting the following badness with top of tree on a embedded PowerPC 
> w/a ULI 1575 bridge (M5229 IDE):
>
> 02:1f.0 IDE interface: Acer Laboratories Inc. [ALi] M5229 IDE (rev c8)

Just to be sure that I didn't break the ULi for your board, could
you try locally revert this patch:

commit 52ddd1cdc923802b224b15ba75000c6c5668227f
Author: Anton Vorontsov <avorontsov@ru.mvista.com>
Date:   Thu Jun 12 03:04:17 2008 +0400

    powerpc/85xx/86xx: some refactoring for fsl_uli1575 code

And see if this helps?

> If you need more info let me know.
>
> - k
>
> ahci 0000:02:1f.1: AHCI 0001.0000 32 slots 4 ports 3 Gbps 0xf impl SATA 
> mode
> ahci 0000:02:1f.1: flags: ncq sntf ilck pm led clo pmp pio slum part
> ------------[ cut here ]------------
> Badness at c021e700 [verbose debug info unavailable]
> NIP: c021e700 LR: c021e6e8 CTR: c022ce90
> REGS: ef82bca0 TRAP: 0700   Not tainted  (2.6.27-rc1-00495-g33bd9fe- 
> dirty)
> MSR: 00029032 <EE,ME,IR,DR>  CR: 22044022  XER: 20000000
> TASK = ef830000[1] 'swapper' THREAD: ef82a000 CPU: 1
> GPR00: 00000001 ef82bd50 ef830000 00000000 00009032 00000000 ef0b64fc  
> 00000000
> GPR08: ef937c10 c022f93f efbfc8e0 ef900b60 22044028 fffdd3ff 0ffe8700  
> c044c17c
> GPR16: c04d52ec ef82f458 ef82f4f4 ef82f4f4 c044c234 c044c5d8 c044c5d8  
> c044c220
> GPR24: c044c218 c04d52f0 00000080 c022f940 00000000 c044c244 efbec490  
> 00000000
> NIP [c021e700] ata_host_activate+0x40/0x10c
> LR [c021e6e8] ata_host_activate+0x28/0x10c
> Call Trace:
> [ef82bd50] [c021e6e8] ata_host_activate+0x28/0x10c (unreliable)
> [ef82bd80] [c022f48c] ahci_init_one+0x8b4/0xd68
> [ef82be30] [c01b69c0] pci_device_probe+0x84/0xa8
> [ef82be50] [c01e5438] driver_probe_device+0xb4/0x1e8
> [ef82be70] [c01e55f0] __driver_attach+0x84/0x88
> [ef82be90] [c01e4ba0] bus_for_each_dev+0x5c/0xa4
> [ef82bec0] [c01e5254] driver_attach+0x24/0x34
> [ef82bed0] [c01e44b8] bus_add_driver+0x1d8/0x24c
> [ef82bef0] [c01e5810] driver_register+0x70/0x160
> [ef82bf10] [c01b6c54] __pci_register_driver+0x64/0xc4
> [ef82bf30] [c04aaa60] ahci_init+0x28/0x38
> [ef82bf40] [c048717c] do_one_initcall+0x38/0x1ac
> [ef82bfb0] [c04874e0] kernel_init+0x1f0/0x1fc
> [ef82bff0] [c0013b04] kernel_thread+0x44/0x60
> Instruction dump:
> 7cbb2b78 90010034 7cda3378 7cf93b78 7c7e1b78 4bff9dbd 7c7f1b79 408200c8
> 2f9c0000 409e002c 313bffff 7c09d910 <0f000000> 80010034 7fc3f378  
> 7f24cb78
> scsi0 : ahci
> scsi1 : ahci
> scsi2 : ahci
> scsi3 : ahci
> ata1: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006100
> ata2: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006180
> ata3: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006200
> ata4: SATA max UDMA/133 abar m1024@0x80006000 port 0x80006280
> ata1: SATA link down (SStatus 0 SControl 300)
> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> ata2.00: qc timeout (cmd 0xec)
> ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)

-- 
Anton Vorontsov
email: cbouatmailru@gmail.com
irc://irc.freenode.net/bd2

Re: libata badness

[Kumar Gala]

I figured out the issue.  Its related to the interrupt routing being  
conveyed to the code from the device tree.  We have a missing 'space'  
causing issues.

- k

Re: libata badness

[Ben Dooks]

On Thu, Jul 31, 2008 at 04:58:05PM -0500, Kumar Gala wrote:
> I figured out the issue.  Its related to the interrupt routing being  
> conveyed to the code from the device tree.  We have a missing 'space'  
> causing issues.

out of interest, is the M5229 attached to a single IRQ in this device
or has the bridge been configured to route the IRQs from the IDE to
the same pin on the PIC?

-- 
Ben

Q:      What's a light-year?
A:      One-third less calories than a regular year.

Re: libata badness

[Kumar Gala]

On Aug 1, 2008, at 5:43 AM, Ben Dooks wrote:

> On Thu, Jul 31, 2008 at 04:58:05PM -0500, Kumar Gala wrote:
>> I figured out the issue.  Its related to the interrupt routing being
>> conveyed to the code from the device tree.  We have a missing 'space'
>> causing issues.
>
> out of interest, is the M5229 attached to a single IRQ in this device
> or has the bridge been configured to route the IRQs from the IDE to
> the same pin on the PIC?

The bridge is routing interrupts via an i8259 to a single interrupt on  
the OpenPIC (primary pic).

- k