sata_mv: hard resetting port

This are the log entries I saw as I started e2fsck on a 5-disk Linux RAID-5 array; all disks connected to a sata_mv controller:

Nov 13 18:57:33 superthecus kernel: ata6.00: exception Emask 0x1 SAct 0x0 SErr 0x100000 action 0x6 frozen
Nov 13 18:57:34 superthecus kernel: ata6.00: edma_err 0x00000084, EDMA self-disable
Nov 13 18:57:34 superthecus kernel: ata6.00: cmd 25/00:00:bf:09:24/00:02:1c:00:00/e0 tag 0 cdb 0x0 data 262144 in
Nov 13 18:57:34 superthecus kernel:          res 51/84:00:bf:09:24/84:02:1c:00:00/e0 Emask 0x10 (ATA bus error)
Nov 13 18:57:34 superthecus kernel: ata6: hard resetting port
Nov 13 18:57:34 superthecus kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Nov 13 18:57:34 superthecus kernel: ata6.00: configured for UDMA/133
Nov 13 18:57:34 superthecus kernel: ata6: EH complete
Nov 13 18:57:34 superthecus kernel: sd 5:0:0:0: [sde] 781422768 512-byte hardware sectors (400088 MB)
Nov 13 18:57:34 superthecus kernel: sd 5:0:0:0: [sde] Write Protect is off
Nov 13 18:57:34 superthecus kernel: sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
Nov 13 18:57:34 superthecus kernel: sd 5:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov 13 18:57:37 superthecus kernel: ata6: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
Nov 13 18:57:37 superthecus kernel: ata6: edma_err 0x00000020
Nov 13 18:57:37 superthecus kernel: ata6: hard resetting port
Nov 13 18:57:37 superthecus kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Nov 13 18:57:37 superthecus kernel: ata6.00: configured for UDMA/133
Nov 13 18:57:37 superthecus kernel: ata6: EH pending after completion, repeating EH (cnt=4)
Nov 13 18:57:37 superthecus kernel: ata6: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0x7
Nov 13 18:57:37 superthecus kernel: ata6: edma_err 0x00000010, dev connect
Nov 13 18:57:37 superthecus kernel: ata6: hard resetting port
Nov 13 18:57:37 superthecus kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Nov 13 18:57:38 superthecus kernel: ata6.00: configured for UDMA/133
Nov 13 18:57:38 superthecus kernel: ata6: EH complete
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] 781422768 512-byte hardware sectors (400088 MB)
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] Write Protect is off
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] 781422768 512-byte hardware sectors (400088 MB)
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] Write Protect is off
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
Nov 13 18:57:38 superthecus kernel: sd 5:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA

That's the Marvell controller:

01:00.0 SCSI storage controller: Marvell Technology Group Ltd. MV88SX6081 8-port SATA II PCI-X Controller (rev 09)

smartctl didn't show any errors.

Tomasz Chmielewski
http://lists.wpkg.org

..

Translation:
"The port had a link CRC error, which caused it to drop out of host-queuing mode."

..

Translation:
"libata reset the link, and everything appeared okay, so it reissued the failed command and continued. No data loss."

Is there an online Kernelish-English dictionary anywhere? ;)

Tomasz Chmielewski
http://wpkg.org

..

Unfortunately not.

At some point, we *really* need to convice {Tejun,Jeff} that libata messages should be simpler, fewer, and more human readable by default, with perhaps a sysfs flag to re-enable the {Tejun,Jeff}-speak versions.

Cheers

Ummm... Okay. That might have something to do with me not being a native speaker. :-)

I agree that the current message looks too scary and detailed. Yeah, essages for recovered errors can be shorter and sweeter. Those messages are pretty helpful to developers tho. Always having duplicate SCSI messages don't help either.

Thanks. I'm putting it on the todo list but I have to admit it is of low priority ATM.

tejun

..

Nothing bad intended by that.. I can read the current messages just fine :) though there do seem to be a *lot* of them.

But that is good for libata, in it's current level of immaturity and rapid development. In a release or three, once things settle down a bit, we'll likely feel more pressure to make things understandable by others.

Cheers

Note that I only sent this kernel message to this list because I couldn't understand it.

So, I wasn't really helpful to you or Mark, but I actually took your time - to read and reply to this posting. And time is a scarce resource.

My 3 cents.

Tomasz Chmielewski
http://wpkg.org

Mark Lord schrieb:

(...)

And today kernel (2.6.23.1) in the same machine have spoken to not-mere-mortals again:

ata6: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x6 frozen
ata6: edma_err 0x00000020
ata6: hard resetting port
ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata6.00: configured for UDMA/133
ata6: EH complete
sd 5:0:0:0: [sde] 781422768 512-byte hardware sectors (400088 MB)
sd 5:0:0:0: [sde] Write Protect is off
sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
sd 5:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA

As I understand it now, your previous translation would fit here (or not, as SErr differs?):

But why was the port reseted? There was no CRC error as before, was there?

What worries me is that it always happens for the same drive.

Tomasz Chmielewski
http://wpkg.org

..

Here, the messages fail us. The edma_err value says that there should be a non-zero value in the SErr value. Except the messages show zero there, meaning the registers were probably read in the wrong sequence (some bits clear automatically on reads).

In any event, the messages that follow don't say anything about I/O failing in any way, so again this is nothing to be concerned about unless it happens frequently.

At this point, I would unplug/replug all of the SATA cables, to ensure they have good connections.

..

I think the error-handling code is a bit heavy handed,
in that the port reset was not actually needed in the prior case either.

But this way it is simple, consistent, and does work. It just prints too many messages.

..

Twiddle with the cabling for that drive, and it will probably behave.

..

No, it's just funny status. The chipset (Marvell) claims it saw a SATA error. But the SATA error register is all-zeros, meaning "no error".

I think somebody forgot to save the latter before clearing it, or somebody forgot to clear the former from an earlier error. Either way, a nuisance, but no harm done here.

..

Mmm.. none in this case (my mistake).