ata1: soft resetting port

ata1: soft resetting port

[Soeren Sonnenburg]

Dear List,

since the switch to 

CONFIG_ATA=y
CONFIG_ATA_ACPI=y
CONFIG_ATA_PIIX=y,

the ATA_PIIX driver manages both, internal sata disk aswell as cd/dvd
rom. However I am being flooded with the error messages below (well they
appear from time to time, dominating dmesg). 

This happens on kernel 2.6.22-rc5, I am copying relevant parts from dmesg:

libata version 2.21 loaded.
ata_piix 0000:00:1f.1: version 2.11
ata1: PATA max UDMA/133 cmd 0x000101f0 ctl 0x000103f6 bmdma 0x000140c0 irq 14
ata2: PATA max UDMA/133 cmd 0x00010170 ctl 0x00010376 bmdma 0x000140c8 irq 15
ata1.00: ATAPI: HL-DT-ST DVDRW GWA4080M, AA26, max UDMA/33
ata1.00: configured for UDMA/33
ATA: abnormal status 0x7F on port 0x00010177
scsi 0:0:0:0: CD-ROM            HL-DT-ST DVDRW GWA4080M   AA26 PQ: 0 ANSI: 5
sr0: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
sr 0:0:0:0: Attached scsi CD-ROM sr0
sr 0:0:0:0: Attached scsi generic sg0 type 5
ata_piix 0000:00:1f.2: MAP [ P0 P2 XX XX ]
ata_piix 0000:00:1f.2: invalid MAP value 0
PCI: Setting latency timer of device 0000:00:1f.2 to 64
scsi2 : ata_piix
scsi3 : ata_piix
ata3: SATA max UDMA/133 cmd 0x000140d8 ctl 0x000140f6 bmdma 0x00014020 irq 0
ata4: SATA max UDMA/133 cmd 0x000140d0 ctl 0x000140f2 bmdma 0x00014028 irq 0
ata3.01: ata_hpa_resize 1: sectors = 234441648, hpa_sectors = 234441648
ata3.01: ATA-7: ST9120821AS, 7.01, max UDMA/133
ata3.01: 234441648 sectors, multi 16: LBA48 NCQ (depth 0/32)
ata3.01: ata_hpa_resize 1: sectors = 234441648, hpa_sectors = 234441648
ata3.01: configured for UDMA/133
ATA: abnormal status 0x7F on port 0x000140d7


the actual errors:


ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata1.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/24:03:00:00:20/00:00:00:00:00/a0 Emask 0x1 (device error)
ata1.00: configured for UDMA/33
ata1: EH complete
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2
ata1.00: (BMDMA stat 0x5)
ata1.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x25 data 8 in
         res 00/24:03:00:00:00/00:00:00:00:00/a0 Emask 0x2 (HSM violation)
ata1: soft resetting port
ata1.00: configured for UDMA/33
ata1: EH complete
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2
ata1.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 00/24:03:00:00:20/00:00:00:00:00/a0 Emask 0x2 (HSM violation)
ata1: soft resetting port
ata1.00: configured for UDMA/33
ata1: EH complete
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2
ata1.00: (BMDMA stat 0x5)
ata1.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x25 data 8 in
         res 00/24:03:00:00:00/00:00:00:00:00/a0 Emask 0x2 (HSM violation)
ata1: soft resetting port
ata1.00: configured for UDMA/33
ata1: EH complete
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2
ata1.00: (BMDMA stat 0x5)
ata1.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x43 data 12 in
         res 00/24:03:00:00:00/00:00:00:00:00/a0 Emask 0x2 (HSM violation)
ata1: soft resetting port
ata1.00: configured for UDMA/33
ata1: EH complete
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata1.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/24:03:00:00:20/00:00:00:00:00/a0 Emask 0x1 (device error)
ata1.00: configured for UDMA/33
ata1: EH complete
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata1.00: (BMDMA stat 0x5)
ata1.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x25 data 8 in
         res 51/24:03:00:00:00/00:00:00:00:00/a0 Emask 0x1 (device error)
ata1.00: configured for UDMA/33
ata1: EH complete
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2
ata1.00: (BMDMA stat 0x5)
ata1.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x43 data 12 in
         res 00/24:03:00:00:00/00:00:00:00:00/a0 Emask 0x2 (HSM violation)
ata1: soft resetting port

-- 
Sometimes, there's a moment as you're waking, when you become aware of
the real world around you, but you're still dreaming.

Re: ata1: soft resetting port

[Tejun Heo]

Soeren Sonnenburg wrote:
> Dear List,
> 
> since the switch to 
> 
> CONFIG_ATA=y
> CONFIG_ATA_ACPI=y
> CONFIG_ATA_PIIX=y,
> 
> the ATA_PIIX driver manages both, internal sata disk aswell as cd/dvd
> rom. However I am being flooded with the error messages below (well they
> appear from time to time, dominating dmesg). 
> 
> This happens on kernel 2.6.22-rc5, I am copying relevant parts from dmesg:

Does 2.6.22-rc7 fare better?

-- 
tejun

Re: ata1: soft resetting port

[Soeren Sonnenburg]

On Tue, 2007-07-03 at 15:40 +0900, Tejun Heo wrote:
> Soeren Sonnenburg wrote:
> > Dear List,
> > 
> > since the switch to 
> > 
> > CONFIG_ATA=y
> > CONFIG_ATA_ACPI=y
> > CONFIG_ATA_PIIX=y,
> > 
> > the ATA_PIIX driver manages both, internal sata disk aswell as cd/dvd
> > rom. However I am being flooded with the error messages below (well they
> > appear from time to time, dominating dmesg). 
> > 
> > This happens on kernel 2.6.22-rc5, I am copying relevant parts from dmesg:
> 
> Does 2.6.22-rc7 fare better?

Yes indeed. The only thing I've seen in the last two days was the
following on resume:

pci_express 0000:00:1c.2:pcie03: resuming
sr 0:0:0:0: resuming
sd 2:0:1:0: resuming
sd 2:0:1:0: [sda] Starting disk
ata1.00: configured for UDMA/33
ata3.01: revalidation failed (errno=-2)
ata3: failed to recover some devices, retrying in 5 secs
ata3.01: configured for UDMA/133

Soeren
-- 
Sometimes, there's a moment as you're waking, when you become aware of
the real world around you, but you're still dreaming.

Re: ata1: soft resetting port

[Tejun Heo]

Soeren Sonnenburg wrote:
> On Tue, 2007-07-03 at 15:40 +0900, Tejun Heo wrote:
>> Soeren Sonnenburg wrote:
>>> Dear List,
>>>
>>> since the switch to 
>>>
>>> CONFIG_ATA=y
>>> CONFIG_ATA_ACPI=y
>>> CONFIG_ATA_PIIX=y,
>>>
>>> the ATA_PIIX driver manages both, internal sata disk aswell as cd/dvd
>>> rom. However I am being flooded with the error messages below (well they
>>> appear from time to time, dominating dmesg). 
>>>
>>> This happens on kernel 2.6.22-rc5, I am copying relevant parts from dmesg:
>> Does 2.6.22-rc7 fare better?
> 
> Yes indeed. The only thing I've seen in the last two days was the
> following on resume:
> 
> pci_express 0000:00:1c.2:pcie03: resuming
> sr 0:0:0:0: resuming
> sd 2:0:1:0: resuming
> sd 2:0:1:0: [sda] Starting disk
> ata1.00: configured for UDMA/33
> ata3.01: revalidation failed (errno=-2)
> ata3: failed to recover some devices, retrying in 5 secs
> ata3.01: configured for UDMA/133

Hmmm... That's NODEV_HINT being triggered after resume.  Probably the
device isn't ready to respond yet at that point.  How reproducible is
the problem?

-- 
tejun

Re: ata1: soft resetting port

[Soeren Sonnenburg]

On Thu, 2007-07-05 at 03:01 +0900, Tejun Heo wrote:
> Soeren Sonnenburg wrote:
> > On Tue, 2007-07-03 at 15:40 +0900, Tejun Heo wrote:
> >> Soeren Sonnenburg wrote:
> >>> Dear List,
> >>>
> >>> since the switch to 
> >>>
> >>> CONFIG_ATA=y
> >>> CONFIG_ATA_ACPI=y
> >>> CONFIG_ATA_PIIX=y,
> >>>
> >>> the ATA_PIIX driver manages both, internal sata disk aswell as cd/dvd
> >>> rom. However I am being flooded with the error messages below (well they
> >>> appear from time to time, dominating dmesg). 
> >>>
> >>> This happens on kernel 2.6.22-rc5, I am copying relevant parts from dmesg:
> >> Does 2.6.22-rc7 fare better?
> > 
> > Yes indeed. The only thing I've seen in the last two days was the
> > following on resume:
> > 
> > pci_express 0000:00:1c.2:pcie03: resuming
> > sr 0:0:0:0: resuming
> > sd 2:0:1:0: resuming
> > sd 2:0:1:0: [sda] Starting disk
> > ata1.00: configured for UDMA/33
> > ata3.01: revalidation failed (errno=-2)
> > ata3: failed to recover some devices, retrying in 5 secs
> > ata3.01: configured for UDMA/133
> 
> Hmmm... That's NODEV_HINT being triggered after resume.  Probably the
> device isn't ready to respond yet at that point.  How reproducible is
> the problem?

quite reproducible:

$ dmesg | grep 'revalidation failed' | wc -l
4

Soeren
-- 
Sometimes, there's a moment as you're waking, when you become aware of
the real world around you, but you're still dreaming.

Re: ata1: soft resetting port

[Tejun Heo]

Soeren Sonnenburg wrote:
>>> pci_express 0000:00:1c.2:pcie03: resuming
>>> sr 0:0:0:0: resuming
>>> sd 2:0:1:0: resuming
>>> sd 2:0:1:0: [sda] Starting disk
>>> ata1.00: configured for UDMA/33
>>> ata3.01: revalidation failed (errno=-2)
>>> ata3: failed to recover some devices, retrying in 5 secs
>>> ata3.01: configured for UDMA/133
>> Hmmm... That's NODEV_HINT being triggered after resume.  Probably the
>> device isn't ready to respond yet at that point.  How reproducible is
>> the problem?
> 
> quite reproducible:
> 
> $ dmesg | grep 'revalidation failed' | wc -l
> 4

Hmmm... Thanks.  I think the best we can do is 1. don't wait for disk
revalidation during resume 2. retry faster.  Just in case, please post
the result of "hdparm -I /dev/sdX" where sdX is the device at ata3.01.

-- 
tejun