Hello,
We have a bespoke platform utilising a Marvell MV88SX6041 SATA controller on which we have been running Linux 2.6.26 and using the sata_mv driver.
We have noticed problems with SATA ports occasionally locking up (on hotplug events) and remaining unresponsive. The normal kernel logging that occurs on hotplug events is no longer emitted for the locked ports (but will be emitted for the other sata ports that have not exhibited the problem.) The disks attached to the locked ports are completely unresponsive. The condition can be cleared by removing the sata_mv kernel module from memory and reloading it, after which the kernel logging becomes active (and the disks are usable) for all ports.
The following changeset was seen as a strong candidate for addressing this problem:
http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=933cb8e5fcdebd4b666165e3f039f814d62b0e52
We are now in the process of upgrading to the stable 2.6.38.2 kernel release, but initial testing of this on our platform exhibits the same hotplug behaviour. Hotplug is possible, but occasionally the ports will lock up and not be responsive until sata_mv is removed and reinstalled. Other than this, the new kernel and driver seem to be operating normally.
Has this problem been observed elsewhere with kernels that include the above patch? Please CC me in replies.
Kind Regards,
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
Latest News at: http://www.indigovision.com/news2011.php
Please accept my most humble apologies for the lack of line breaks in
my previous email. Here it is again, this time in a more readable
format:
Hello,
We have a bespoke platform utilising a Marvell MV88SX6041 SATA controller
on which we have been running Linux 2.6.26 and using the sata_mv driver.
We have noticed problems with SATA ports occasionally locking up (on
hotplug events) and remaining unresponsive. The normal kernel logging
that occurs on hotplug events is no longer emitted for the locked ports
(but will be emitted for the other sata ports that have not exhibited
the problem.) The disks attached to the locked ports are completely
unresponsive. The condition can be cleared by removing the sata_mv
kernel module from memory and reloading it, after which the kernel
logging becomes active (and the disks are usable) for all ports.
The following changeset was seen as a strong candidate for addressing
this problem:
http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=933cb8e5fcdebd4b666165e3f039f814d62b0e52
We are now in the process of upgrading to the stable 2.6.38.2 kernel
release, but initial testing of this on our platform exhibits the same
hotplug behaviour. Hotplug is possible, but occasionally the ports
will lock up and not be responsive until sata_mv is removed and
reinstalled. Other than this, the new kernel and driver seem to be
operating normally.
Has this problem been observed elsewhere with kernels that include the
above patch? Please CC me in replies.
Kind Regards,
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
Latest News at: http://www.indigovision.com/news2011.php
On 11-04-06 10:57 AM, Bruce Stenning wrote:
> Please accept my most humble apologies for the lack of line breaks in
> my previous email. Here it is again, this time in a more readable
> format:
>
> Hello,
>
> We have a bespoke platform utilising a Marvell MV88SX6041 SATA controller
> on which we have been running Linux 2.6.26 and using the sata_mv driver.
>
> We have noticed problems with SATA ports occasionally locking up (on
> hotplug events) and remaining unresponsive. The normal kernel logging
> that occurs on hotplug events is no longer emitted for the locked ports
> (but will be emitted for the other sata ports that have not exhibited
> the problem.) The disks attached to the locked ports are completely
> unresponsive. The condition can be cleared by removing the sata_mv
> kernel module from memory and reloading it, after which the kernel
> logging becomes active (and the disks are usable) for all ports.
>
> The following changeset was seen as a strong candidate for addressing
> this problem:
>
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=933cb8e5fcdebd4b666165e3f039f814d62b0e52
That changeset is already in upstream kernels (kernel.org).
Does the latest kernel (2.6.38) w/ sata_mv work ?
El Wed, 6 Apr 2011 15:57:06 +0100
Bruce Stenning <[email protected]> escribió:
Just CCing linux-ide
> Please accept my most humble apologies for the lack of line breaks in
> my previous email. Here it is again, this time in a more readable
> format:
>
> Hello,
>
> We have a bespoke platform utilising a Marvell MV88SX6041 SATA controller
> on which we have been running Linux 2.6.26 and using the sata_mv driver.
>
> We have noticed problems with SATA ports occasionally locking up (on
> hotplug events) and remaining unresponsive. The normal kernel logging
> that occurs on hotplug events is no longer emitted for the locked ports
> (but will be emitted for the other sata ports that have not exhibited
> the problem.) The disks attached to the locked ports are completely
> unresponsive. The condition can be cleared by removing the sata_mv
> kernel module from memory and reloading it, after which the kernel
> logging becomes active (and the disks are usable) for all ports.
>
> The following changeset was seen as a strong candidate for addressing
> this problem:
>
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=933cb8e5fcdebd4b666165e3f039f814d62b0e52
>
> We are now in the process of upgrading to the stable 2.6.38.2 kernel
> release, but initial testing of this on our platform exhibits the same
> hotplug behaviour. Hotplug is possible, but occasionally the ports
> will lock up and not be responsive until sata_mv is removed and
> reinstalled. Other than this, the new kernel and driver seem to be
> operating normally.
>
> Has this problem been observed elsewhere with kernels that include the
> above patch? Please CC me in replies.
>
> Kind Regards,
>
> Bruce Stenning,
> IndigoVision,
> b <dot> stenning <at> indigovision <dot> com
>
>
> Latest News at: http://www.indigovision.com/news2011.php
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
Hi Mark,
> On 11-04-06 10:57 AM, Bruce Stenning wrote:
> > [...]
> >
> > The following changeset was seen as a strong candidate for addressing
> > this problem:
> >
> > http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=933cb8e5fcdebd4b666165e3f039f814d62b0e52
>
> That changeset is already in upstream kernels (kernel.org).
> Does the latest kernel (2.6.38) w/ sata_mv work ?
The 2.6.38.2 kernel still exhibits the same lockups that we see with the
2.6.26 kernel.
Alejandro Riveira Fernández kindly forwarded my email to the linux-ide list,
so I shall take the discussion there and away from the main kernel list.
Kind Regards,
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
Latest News at: http://www.indigovision.com/news2011.php
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
On 11-04-08 08:43 AM, Bruce Stenning wrote:
> Hi Mark,
>
>> On 11-04-06 10:57 AM, Bruce Stenning wrote:
>>> [...]
>>>
>>> The following changeset was seen as a strong candidate for addressing
>>> this problem:
>>>
>>> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=933cb8e5fcdebd4b666165e3f039f814d62b0e52
>>
>> That changeset is already in upstream kernels (kernel.org).
>> Does the latest kernel (2.6.38) w/ sata_mv work ?
>
> The 2.6.38.2 kernel still exhibits the same lockups that we see with the
> 2.6.26 kernel.
Okay. Just to help narrow it down a bit, how does 2.6.32 behave ?
Thanks.
> > The 2.6.38.2 kernel still exhibits the same lockups that we see with the
> > 2.6.26 kernel.
>
> Okay. Just to help narrow it down a bit, how does 2.6.32 behave ?
>
> Thanks.
Hi Mark,
I have reproduced the issue with the 2.6.32 kernel.
In case it is of use, the silicon is rev 09 (i.e. C0 stepping) and I am using
gcc 4.4.2 to build the kernel and modules.
I am currently inserting tracing into 2.6.38.2 to try to work out what is going
on. From mv_write_main_irq_mask I can see that the IRQ for each port is still
enabled, even when ports stop responding. I see interrupts generated when I
hotplug or unplug disks on ports that are not locked up, but no interrupt is
generated at all for the ports that are locked (this is from tracing in
asm_do_IRQ in arch/arm/kernel/irq.c)
One thing I noticed was that there is no spinlock around the
mv_save_cached_regs/mv_edma_cfg in mv_hardreset (unlike mv_port_start and
mv_port_stop); why is this?
Kind Regards,
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
Latest News at: http://www.indigovision.com/index.php/en/news.html
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
On 11-04-12 06:30 AM, Bruce Stenning wrote:
>
> I have reproduced the issue with the 2.6.32 kernel.
Perfect. This means that it probably wasn't broken by somebody else
since I last looked at the code two years ago. :)
>
> In case it is of use, the silicon is rev 09 (i.e. C0 stepping) and I am using
> gcc 4.4.2 to build the kernel and modules.
"C0" is *good*.
> I am currently inserting tracing into 2.6.38.2 to try to work out what is going
> on. From mv_write_main_irq_mask I can see that the IRQ for each port is still
> enabled, even when ports stop responding. I see interrupts generated when I
> hotplug or unplug disks on ports that are not locked up, but no interrupt is
> generated at all for the ports that are locked (this is from tracing in
> asm_do_IRQ in arch/arm/kernel/irq.c)
>
> One thing I noticed was that there is no spinlock around the
> mv_save_cached_regs/mv_edma_cfg in mv_hardreset (unlike mv_port_start and
> mv_port_stop); why is this?
The mv_hardreset path is run from a libata-eh thread,
and it assumes it has exclusive access to the hardware.
But by all means, stuff the spinlock around that pair of calls,
just to eliminate any possibility of my mis-thinking it there.
I'm going to take a few minutes now and try to re-understand
how hot-plug gets "armed" for use, and see if anything cries out at me.
Cheers
On 11-04-12 10:07 AM, Mark Lord wrote:
> On 11-04-12 06:30 AM, Bruce Stenning wrote:
..
>> I am currently inserting tracing into 2.6.38.2 to try to work out what is going
>> on. From mv_write_main_irq_mask I can see that the IRQ for each port is still
>> enabled, even when ports stop responding. I see interrupts generated when I
>> hotplug or unplug disks on ports that are not locked up, but no interrupt is
>> generated at all for the ports that are locked (this is from tracing in
>> asm_do_IRQ in arch/arm/kernel/irq.c)
>>
>> One thing I noticed was that there is no spinlock around the
>> mv_save_cached_regs/mv_edma_cfg in mv_hardreset (unlike mv_port_start and
>> mv_port_stop); why is this?
>
> The mv_hardreset path is run from a libata-eh thread,
> and it assumes it has exclusive access to the hardware.
Mmm.. another suspect is sata_mv's ".sff_irq_clear" function.
I don't see any locking in libata-sff.c before calling that one.
Tejun -- should libata-sff grab ap->lock before calling .sff_irq_clear,
or is that up to the LLD to do?
Thanks.
On 11-04-12 06:30 AM, Bruce Stenning wrote:
..
> I am currently inserting tracing into 2.6.38.2 to try to work out what is going
> on. From mv_write_main_irq_mask I can see that the IRQ for each port is still
> enabled, even when ports stop responding.
..
> One thing I noticed was that there is no spinlock around the
> mv_save_cached_regs/mv_edma_cfg in mv_hardreset (unlike mv_port_start and
> mv_port_stop); why is this?
Yeah, I'm suspecting there's a loophole in the logic there somewhere.
I dusted off the 6041 reference card I have here, and played with the cables
for a while. Managed to get one port to stop responding to hot plug fairly
quickly, though I'm not sure how/why.
Then I added a debug printk() to mv_write_main_irq_mask(),
with no other changes, and that appears to have been enough
to change the race timing so that I could no longer produce
the problem.
Bruce, here's a slightly-ugly patch that should remove all
doubt about races in the irq_mask. Please apply it, test with it,
and let me know here if the issue goes away.
Thanks
--- old/drivers/ata/sata_mv.c 2011-04-13 11:03:07.442481426 -0400
+++ linux/drivers/ata/sata_mv.c 2011-04-13 11:07:55.224249621 -0400
@@ -1027,15 +1027,19 @@
static void mv_set_main_irq_mask(struct ata_host *host,
u32 disable_bits, u32 enable_bits)
{
+ static spinlock_t irq_mask_lock = __SPIN_LOCK_UNLOCKED(irq_mask_lock); //
FIXME: per-host would be nicer
struct mv_host_priv *hpriv = host->private_data;
u32 old_mask, new_mask;
+ unsigned long flags;
+ spin_lock_irqsave(&irq_mask_lock, flags);
old_mask = hpriv->main_irq_mask;
new_mask = (old_mask & ~disable_bits) | enable_bits;
if (new_mask != old_mask) {
hpriv->main_irq_mask = new_mask;
mv_write_main_irq_mask(new_mask, hpriv);
}
+ spin_unlock_irqrestore(&irq_mask_lock, flags);
}
static void mv_enable_port_irqs(struct ata_port *ap,
> Yeah, I'm suspecting there's a loophole in the logic there somewhere.
>
> I dusted off the 6041 reference card I have here, and played with the cables for a while. Managed to > get one port to stop responding to hot plug fairly quickly, though I'm not sure how/why.
>
> Then I added a debug printk() to mv_write_main_irq_mask(), with no other changes, and that appears to > have been enough to change the race timing so that I could no longer produce the problem.
>
> Bruce, here's a slightly-ugly patch that should remove all doubt about races in the irq_mask. Please > apply it, test with it, and let me know here if the issue goes away.
>
> Thanks
Thanks Mark. I was about to try out some tracing in writelfl because I
suspected the irq mask was getting clobbered somewhere along the way, but
I'd been distracted by other work. I shall try your patch out as soon as
I can, and report back.
Cheers,
Bruce.
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
Latest News at: http://www.indigovision.com/index.php/en/news.html
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
> > One thing I noticed was that there is no spinlock around the
> > mv_save_cached_regs/mv_edma_cfg in mv_hardreset (unlike mv_port_start
> > and mv_port_stop); why is this?
>
> Yeah, I'm suspecting there's a loophole in the logic there somewhere.
>
> I dusted off the 6041 reference card I have here, and played with the cables
> for a while. Managed to get one port to stop responding to hot plug fairly
> quickly, though I'm not sure how/why.
>
> Then I added a debug printk() to mv_write_main_irq_mask(), with no other
> changes, and that appears to have been enough to change the race timing
> so that I could no longer produce the problem.
>
> Bruce, here's a slightly-ugly patch that should remove all doubt about races
> in the irq_mask. Please apply it, test with it, and let me know here if the
> issue goes away.
>
> Thanks
>
> [patch]
Hi Mark,
I have tried the patch out and I was able to reproduce the port lockup with it.
I also tried out my tracing in writelfl (without any other changes) and I was
able to lock up a port without any apparent unusual changes to the register
containing the irq masks. Are there other routes to disabling the irqs?
I shall continue looking.
Cheers,
Bruce.
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
Latest News at: http://www.indigovision.com/index.php/en/news.html
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
On 11-04-14 12:50 PM, Bruce Stenning wrote:
..
> I have tried the patch out and I was able to reproduce the port lockup with it.
Bummer.
> I also tried out my tracing in writelfl (without any other changes) and I was
> able to lock up a port without any apparent unusual changes to the register
> containing the irq masks. Are there other routes to disabling the irqs?
Mmm.. presumably you are NOT using MSI interrupts, right?
On Fri, 8 Apr 2011, Bruce Stenning wrote:
> The 2.6.38.2 kernel still exhibits the same lockups that we see with the
> 2.6.26 kernel.
Hi.
I have some input on this. I have one of these controllers and had
problems with one channel where if I had a drive in that hotswap bay, the
controller wouldn't even POST at boot. It just stuck in the detection
phase in the controller BIOS.
When I tested hotplugging into that bay when the system was running, I
received a kernel warning (it's not powered on at the moment so I can't
provide the output, if it's important I can get it).
My point is that there might be a problem with this controller hw or
firmware that doesn't handle all behaviour/situations properly. I
re-seated the SATA cable at both ends and after that couldn't reproduce
the problem (which was reproduced with two different make harddrives
several times before re-seating the cable).
This was with the 2.6.32 debian stable kernel, AMD64 version.
--
Mikael Abrahamsson email: [email protected]
On 11-04-14 11:15 PM, Mikael Abrahamsson wrote:
> On Fri, 8 Apr 2011, Bruce Stenning wrote:
>
>> The 2.6.38.2 kernel still exhibits the same lockups that we see with the
>> 2.6.26 kernel.
>
> Hi.
>
> I have some input on this. I have one of these controllers and had problems with
> one channel where if I had a drive in that hotswap bay, the controller wouldn't
> even POST at boot. It just stuck in the detection phase in the controller BIOS.
>
> When I tested hotplugging into that bay when the system was running, I received
> a kernel warning (it's not powered on at the moment so I can't provide the
> output, if it's important I can get it).
I would like to see the output, next time you can get it.
The thing with the 6041 chip, is that I actually have all of the Marvell
documentation and errata info for the chip. So in theory, we know everything
about it, and there are no secret failure modes yet to be discovered.
The sata_mv driver does not depend on the board's BIOS for anything either.
That's the theory, anyway. :)
Cheers
On Thu, 14 Apr 2011, Mark Lord wrote:
> I would like to see the output, next time you can get it.
Apr 14 18:39:54 host kernel: [ 137.276051] ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Apr 14 18:39:54 host kernel: [ 137.284557] ------------[ cut here ]------------
Apr 14 18:39:54 host kernel: [ 137.284626] WARNING: at /build/buildd-linux-2.6_2.6.32-31-amd64-vrfdM4/linux-2.6-2.6.32/debian/build/source_amd64_none/drivers/ata/libata-sff.c:1208 ata_sff_hsm_move+0x47/0x642 [libata]()
Apr 14 18:39:54 host kernel: [ 137.284733] Hardware name: P5E WS Pro
Apr 14 18:39:54 host kernel: [ 137.284797] Modules linked in: ext2 loop snd_pcm snd_timer snd soundcore snd_page_alloc i2c_i801 i2c_core evdev pcspkr asus_atk0110 x38_edac shpchp pci_hotplug edac_core button processor ext3 jbd mbcache sha256_generic aes_x86_64 aes_generic cbc dm_crypt dm_mod usbhid hid sd_mod crc_t10dif sata_mv uhci_hcd sata_sil24 ahci mpt2sas libata sky2 scsi_transport_sas thermal ehci_hcd thermal_sys scsi_mod usbcore nls_base [last unloaded: scsi_wait_scan]
Apr 14 18:39:54 host kernel: [ 137.286426] Pid: 240, comm: ata/1 Not tainted 2.6.32-5-amd64 #1
Apr 14 18:39:54 host kernel: [ 137.286482] Call Trace:
Apr 14 18:39:54 host kernel: [ 137.286536] [<ffffffffa00b1438>] ? ata_sff_hsm_move+0x47/0x642 [libata]
Apr 14 18:39:54 host kernel: [ 137.286597] [<ffffffffa00b1438>] ? ata_sff_hsm_move+0x47/0x642 [libata]
Apr 14 18:39:54 host kernel: [ 137.286658] [<ffffffff8104df00>] ? warn_slowpath_common+0x77/0xa3
Apr 14 18:39:54 host kernel: [ 137.286718] [<ffffffffa00b1438>] ? ata_sff_hsm_move+0x47/0x642 [libata]
Apr 14 18:39:54 host kernel: [ 137.286780] [<ffffffffa00b1d87>] ? ata_pio_task+0x9a/0xa6 [libata]
Apr 14 18:39:54 host kernel: [ 137.286838] [<ffffffff8106186b>] ? worker_thread+0x188/0x21d
Apr 14 18:39:54 host kernel: [ 137.286897] [<ffffffffa00b1ced>] ? ata_pio_task+0x0/0xa6 [libata]
Apr 14 18:39:54 host kernel: [ 137.286955] [<ffffffff81064e96>] ? autoremove_wake_function+0x0/0x2e
Apr 14 18:39:54 host kernel: [ 137.287012] [<ffffffff810616e3>] ? worker_thread+0x0/0x21d
Apr 14 18:39:54 host kernel: [ 137.287068] [<ffffffff81064bc9>] ? kthread+0x79/0x81
Apr 14 18:39:54 host kernel: [ 137.287124] [<ffffffff81011baa>] ? child_rip+0xa/0x20
Apr 14 18:39:54 host kernel: [ 137.292927] [<ffffffff81064b50>] ? kthread+0x0/0x81
Apr 14 18:39:54 host kernel: [ 137.292984] [<ffffffff81011ba0>] ? child_rip+0x0/0x20
Apr 14 18:39:54 host kernel: [ 137.293041] ---[ end trace 0ce5491cb936fb17 ]---
Apr 14 18:39:54 host kernel: [ 137.306180] ata9.00: failed to IDENTIFY (I/O error, err_mask=0x2)
--
Mikael Abrahamsson email: [email protected]
On 11-04-15 03:43 AM, Mikael Abrahamsson wrote:
> On Thu, 14 Apr 2011, Mark Lord wrote:
>
>> I would like to see the output, next time you can get it.
>
>Apr 14 18:39:54 host kernel: [ 137.276051] ata9: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
>Apr 14 18:39:54 host kernel: [ 137.284557] ------------[ cut here ]------------
>Apr 14 18:39:54 host kernel: [ 137.284626] WARNING: at /build/buildd-linux-2.6_2.6.32-31-amd64-vrfdM4/linux-2.6-2.6.32/debian/build/source_amd64_none/drivers/ata/libata-sff.c:1208 ata_sff_hsm_move+0x47/0x642 [libata]()
>Apr 14 18:39:54 host kernel: [ 137.284733] Hardware name: P5E WS Pro
>Apr 14 18:39:54 host kernel: [ 137.284797] Modules linked in: ext2 loop snd_pcm snd_timer snd soundcore snd_page_alloc i2c_i801 i2c_core evdev pcspkr asus_atk0110 x38_edac shpchp pci_hotplug edac_core button processor ext3 jbd mbcache sha256_generic aes_x86_64 aes_generic cbc dm_crypt dm_mod usbhid hid sd_mod crc_t10dif sata_mv uhci_hcd sata_sil24 ahci mpt2sas libata sky2 scsi_transport_sas thermal ehci_hcd thermal_sys scsi_mod usbcore nls_base [last unloaded: scsi_wait_scan]
>Apr 14 18:39:54 host kernel: [ 137.286426] Pid: 240, comm: ata/1 Not tainted 2.6.32-5-amd64 #1
>Apr 14 18:39:54 host kernel: [ 137.286482] Call Trace:
>Apr 14 18:39:54 host kernel: [ 137.286536] [<ffffffffa00b1438>] ? ata_sff_hsm_move+0x47/0x642 [libata]
>Apr 14 18:39:54 host kernel: [ 137.286597] [<ffffffffa00b1438>] ? ata_sff_hsm_move+0x47/0x642 [libata]
>Apr 14 18:39:54 host kernel: [ 137.286658] [<ffffffff8104df00>] ? warn_slowpath_common+0x77/0xa3
>Apr 14 18:39:54 host kernel: [ 137.286718] [<ffffffffa00b1438>] ? ata_sff_hsm_move+0x47/0x642 [libata]
>Apr 14 18:39:54 host kernel: [ 137.286780] [<ffffffffa00b1d87>] ? ata_pio_task+0x9a/0xa6 [libata]
>Apr 14 18:39:54 host kernel: [ 137.286838] [<ffffffff8106186b>] ? worker_thread+0x188/0x21d
>Apr 14 18:39:54 host kernel: [ 137.286897] [<ffffffffa00b1ced>] ? ata_pio_task+0x0/0xa6 [libata]
>Apr 14 18:39:54 host kernel: [ 137.286955] [<ffffffff81064e96>] ? autoremove_wake_function+0x0/0x2e
>Apr 14 18:39:54 host kernel: [ 137.287012] [<ffffffff810616e3>] ? worker_thread+0x0/0x21d
>Apr 14 18:39:54 host kernel: [ 137.287068] [<ffffffff81064bc9>] ? kthread+0x79/0x81
>Apr 14 18:39:54 host kernel: [ 137.287124] [<ffffffff81011baa>] ? child_rip+0xa/0x20
>Apr 14 18:39:54 host kernel: [ 137.292927] [<ffffffff81064b50>] ? kthread+0x0/0x81
>Apr 14 18:39:54 host kernel: [ 137.292984] [<ffffffff81011ba0>] ? child_rip+0x0/0x20
>Apr 14 18:39:54 host kernel: [ 137.293041] ---[ end trace 0ce5491cb936fb17 ]---
>Apr 14 18:39:54 host kernel: [ 137.306180] ata9.00: failed to IDENTIFY (I/O error, err_mask=0x2)
That's interesting. It really appears have not a lot to do with sata_mv,
though there's no guarantee there.
Tejun -- this is 2.6.32, libata trying to identify a newly hot-plugged drive,
and hitting a warning in libata-sff.c. Looks self-inflicted to me! :)
Mikael -- any chance you could someday retry this on 2.6.38.2 ?
Thanks
> > I also tried out my tracing in writelfl (without any other changes) and I was
> > able to lock up a port without any apparent unusual changes to the register
> > containing the irq masks. Are there other routes to disabling the irqs?
>
> Mmm.. presumably you are NOT using MSI interrupts, right?
Hi Mark,
That is correct:
sata_mv 0000:00:04.0: Gen-II 32 slots 4 ports SCSI mode IRQ via INTx
I am building with CONFIG_ARCH_SUPPORTS_MSI=y, but also with CONFIG_PCI_MSI
not set.
With all this discussion of SATA link speed, I ought to say that we limit our
SATA links to 1.5Gbps with the following kernel parameter:
libata.force=1.5g
I had noticed occasional messages similar to the following earlier in the week:
ata4.00: limiting speed to UDMA/100:PIO4
I was surprised to see them, and thought they might be related to the hotplug
issues, but I was able to reproduce the lockups without these messages being
generated. In some cases (but not all) both sata_down_spd_limit and
ata_down_xfermask_limit are called when backing off the link speed.
Mark, I was intrigued by your comment from the following message:
http://www.spinics.net/lists/linux-ide/msg36922.html
> If it's like their non-AHCI controllers (sata_mv), then the chipset/phy
> could be very particular about the sequence/timing used when changing speeds.
Is it possible that the driver is doing some of the work to change the link
speed (even though it has nowhere to go) and clobbering the link entirely?
I shall take another closer look at the source code and tracing around hotplug
w.r.t. link speed.
Cheers,
Bruce.
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
Latest News at: http://www.indigovision.com/index.php/en/news.html
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
On Fri, 15 Apr 2011, Mark Lord wrote:
> Mikael -- any chance you could someday retry this on 2.6.38.2 ?
Well, since the problem went away after I re-seated the SATA cable, I
don't think I'll even be able to reproduce it with 2.6.32.
--
Mikael Abrahamsson email: [email protected]
On 11-04-15 10:04 AM, Mikael Abrahamsson wrote:
> On Fri, 15 Apr 2011, Mark Lord wrote:
>
>> Mikael -- any chance you could someday retry this on 2.6.38.2 ?
>
> Well, since the problem went away after I re-seated the SATA cable, I don't
> think I'll even be able to reproduce it with 2.6.32.
Right. Thanks.
On 11-04-15 09:21 AM, Bruce Stenning wrote:
..
> sata_mv 0000:00:04.0: Gen-II 32 slots 4 ports SCSI mode IRQ via INTx
..
>
> I had noticed occasional messages similar to the following earlier in the week:
>
> ata4.00: limiting speed to UDMA/100:PIO4
Ugh. Tejun: that's just plain silly.
Why would we EVER EVER EVER fall back to "PIO" for SATA ???
> I am building with CONFIG_ARCH_SUPPORTS_MSI=y, but also with CONFIG_PCI_MSI
> not set.
>
> With all this discussion of SATA link speed, I ought to say that we limit our
> SATA links to 1.5Gbps with the following kernel parameter:
>
> libata.force=1.5g
Mmm... I suppose it could be getting stuck at 1.5g,
and not transitioning back to "auto detect" or something.
That part of sata_mv involves a bit of voo-doo,
because I was reluctant to cut/paste the 200 lines or so
of generic code just for the sake of changing five lines.
Perhaps the generic code has changed since this was originally working,
and now no longer always works for sata_mv..
I suppose you have a good reason for using "libata.force=1.5g" there?
Cheers
> > libata.force=1.5g
>
> Mmm... I suppose it could be getting stuck at 1.5g,
> and not transitioning back to "auto detect" or something.
>
> That part of sata_mv involves a bit of voo-doo,
> because I was reluctant to cut/paste the 200 lines or so
> of generic code just for the sake of changing five lines.
>
> Perhaps the generic code has changed since this was originally working,
> and now no longer always works for sata_mv..
>
> I suppose you have a good reason for using "libata.force=1.5g" there?
Hi Mark,
I hope you had a good weekend.
The SATA speed was limited because there were concerns over signal integrity at
3Gbps early on in our product development, and even at 1.5Gbps the SATA links
are not a bottleneck in our platform. The signal integrity issues have been
addressed, and we would like to remove the limit, but this obviously has an
additional test overhead and it is low down on our priorities.
Out of interest I examined the behaviour of the hotplug with the 1.5Gbps limit
removed, but I saw no change in the port lockup behaviour.
Cheers,
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
Sorry about delay. -EWASTRAVELING
On Tue, Apr 12, 2011 at 10:55:55AM -0400, Mark Lord wrote:
> >> One thing I noticed was that there is no spinlock around the
> >> mv_save_cached_regs/mv_edma_cfg in mv_hardreset (unlike mv_port_start and
> >> mv_port_stop); why is this?
> >
> > The mv_hardreset path is run from a libata-eh thread,
> > and it assumes it has exclusive access to the hardware.
>
> Mmm.. another suspect is sata_mv's ".sff_irq_clear" function.
> I don't see any locking in libata-sff.c before calling that one.
>
> Tejun -- should libata-sff grab ap->lock before calling .sff_irq_clear,
> or is that up to the LLD to do?
It depends. The basic assumption is that inside a single port, most
of exclusions are achieved implicit either by command protocol or
freeze/thaw mechanism - ie. either the port is in known state and
accesses are interlocked or the port is frozen and irq handler won't
do anything interfering with EH until EH brings the port back to sane
state. If something goes wrong in the process, the port will get
frozen and reset, so we should be able to survive most conditions.
Ports on the same host are a bit more complicated. Only a single EH
can proceed on a host. ie. EHs for two separate ports won't proceed
at the same time (ap->eh_owner); however, this doesn't prevent from
normal issue path of another path racing with EH of another port. In
this case, the EH routine should grab the host lock explicitly. The
latter case wasn't common so the compromise for simplicity.
Thanks.
--
tejun
On Fri, Apr 15, 2011 at 11:36:38AM -0400, Mark Lord wrote:
> On 11-04-15 09:21 AM, Bruce Stenning wrote:
> ..
> > sata_mv 0000:00:04.0: Gen-II 32 slots 4 ports SCSI mode IRQ via INTx
> ..
> >
> > I had noticed occasional messages similar to the following earlier in the week:
> >
> > ata4.00: limiting speed to UDMA/100:PIO4
>
> Ugh. Tejun: that's just plain silly.
> Why would we EVER EVER EVER fall back to "PIO" for SATA ???
Nah, it's just printing both DMA and PIO speed settings. It's limited
to UDMA/100 not PIO4.
Thanks.
--
tejun
Hi Mark, Tejun,
> Sorry about delay. -EWASTRAVELING
:-)
After further investigation it looks like there might be more than one thing
going on here. I have managed to lock up ports by unplugging and reinserting
just the sata data cable (thereby avoiding any potential issues with the
hotplug backplane/power.) Dumping the registers after such a lockup shows
clearly that the irq for the locked port is disabled.
I had previously reported that port lockups happened such that the irq for
every port was enabled. I suspect that this is due to the hotplug backplane
on the pre-production unit that I am testing with. Our production units have
proper surge protection on the backplanes, but the early pre-production
versions did not, and I think this is what causes this other mode of port
lockup. Of course, there may be something else going on here but for the
time being I have concentrated on investigating the lockups caused by removing
and reinserting just the sata data cable. The presence of a separate problem
may invalidate other investigations and assertions I had previously made.
I have been able to reproduce this port lockup both with and without the
additional spinlock in mv_set_main_irq_mask. If I add more than very
rudimentary tracing in mv_write_main_irq_mask, then the race is avoided
(as you had indicated, Mark.) I am able to reproduce the lockup with minimal
tracing in mv_write_main_irq_mask and with libata tracing enabled; I have
attached the patch and the tracing leading up to port lockup below (this
is with the additional spinlock in mv_set_main_irq_mask.) Apologies for the
length...
Please note the warning generated by ata_sff_hsm_move on the line:
WARN_ON_ONCE((qc->flags & ATA_QCFLAG_ACTIVE) == 0);
I have been looking at code paths in libata into sata_mv, but I'm afraid I am
not au fait with the libata architecture yet.
Tejun, what does it mean to limit a sata link to UDMA/100? I thought that this
was only for ata devices, and sata devices have the choice of 1.5Gbps, 3Gbps,
or 6 Gbps. Is that a false assumption? Is it related to early sata devices that
were still somewhat based on parallel ata designs?
I shall be out-of-office from Wednesday for the best part of the next three
weeks, but I shall endeavour to get back to you if you have any queries during
that time.
Kind Regards,
Bruce.
Bruce Stenning,
IndigoVision,
b <dot> stenning <at> indigovision <dot> com
@@ -1022,20 +1027,33 @@
if (mask & (ALL_PORTS_COAL_DONE | PORTS_4_7_COAL_DONE))
mask &= ~DONE_IRQ_4_7;
writelfl(mask, hpriv->main_irq_mask_addr);
+#if 1
+ printk("%08x\n", mask);
+#endif
}
[ra_145_82]$ insmod sata_mv.ko
sata_mv 0000:00:04.0: version 1.28
ata_host_alloc: ENTER
ata_port_alloc: ENTER
ata_port_alloc: ENTER
ata_port_alloc: ENTER
ata_port_alloc: ENTER
PCI: enabling device 0000:00:04.0 (0140 -> 0143)
mv_port_init: EDMA cfg=0x0000291f EDMA IRQ err cause/mask=0x00000000/0xfc1e9fff
mv_port_init: EDMA cfg=0x0000291f EDMA IRQ err cause/mask=0x00000000/0xfc1e9fff
mv_port_init: EDMA cfg=0x0000291f EDMA IRQ err cause/mask=0x00000000/0xfc1e9fff
mv_port_init: EDMA cfg=0x0000291f EDMA IRQ err cause/mask=0x00000000/0xfc1e9fff
mv_init_host: HC0: HC config=0x000100ff HC IRQ cause (before clear)=0x00000000
00040000
mv_dump_pci_cfg: 00: 604111ab 02b00143 01000009 00000008
mv_dump_pci_cfg: 10: 80000004 00000000 00001001 00000000
mv_dump_pci_cfg: 20: 00000000 00000000 00000000 11ab11ab
mv_dump_pci_cfg: 30: 00000000 00000040 00000000 0000011a
mv_dump_pci_cfg: 40: 00025001 00000000 00000000 00000000
mv_dump_pci_cfg: 50: 00806005 00000000 00000000 00000000
mv_dump_pci_cfg: 60: 00300007 0183fff8
sata_mv 0000:00:04.0: Gen-II 32 slots 4 ports SCSI mode IRQ via INTx
__ata_port_freeze: ata4294967295 port frozen
__ata_port_freeze: ata4294967295 port frozen
__ata_port_freeze: ata4294967295 port frozen
__ata_port_freeze: ata4294967295 port frozen
scsi0 : sata_mv
scsi1 : sata_mv
scsi2 : sata_mv
scsi3 : sata_mv
ata1: FORCE: PHY spd limit set to 1.5Gbps
ata1: SATA max UDMA/133 mmio m1048576@0x80000000 port 0x80022000 irq 26
ata2: FORCE: PHY spd limit set to 1.5Gbps
ata2: SATA max UDMA/133 mmio m1048576@0x80000000 port 0x80024000 irq 26
ata3: FORCE: PHY spd limit set to 1.5Gbps
ata3: SATA max UDMA/133 mmio m1048576@0x80000000 port 0x80026000 irq 26
ata4: FORCE: PHY spd limit set to 1.5Gbps
ata4: SATA max UDMA/133 mmio m1048576@0x80000000 port 0x80028000 irq 26
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_recover: ENTER
__ata_port_freeze: ata1 port frozen
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata1: bus reset via SRST
ata1: link is slow to respond, please be patient (ready=0)
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040001
ata_eh_thaw_port: ata1 port thawed
ata_std_postreset: ENTER
ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata1: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata1: cmd 0xEC
ata_sff_hsm_move: ata1: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata1: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata1: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata1: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata1: cmd 0x27
ata_sff_hsm_move: ata1: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata1: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0407 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x007f 93==0x0000
ata1.00: ATA-8: ST31000525SV, CV11, max UDMA/133
ata1.00: 1953525168 sectors, multi 0: LBA48 NCQ (depth 31/32)
ata_dev_set_xfermode: set features - xfer mode
ata1: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x46 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata1: cmd 0xEF
ata_sff_hsm_move: ata1: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata1: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata1: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata1: cmd 0xEC
ata_sff_hsm_move: ata1: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata1: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata1: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata1: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata1: cmd 0x27
ata_sff_hsm_move: ata1: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata1: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x407f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x46
ata1.00: configured for UDMA/133
ata_eh_recover: EXIT, rc=0
ata_scsi_error: EXIT
ata_scsi_dump_cdb: CDB (1:0,0,0) 12 00 00 00 24 00 00 00 00
ata_scsiop_inq_std: ENTER
ata_scsi_dump_cdb: CDB (1:0,0,0) 12 00 00 00 60 00 00 00 00
ata_scsiop_inq_std: ENTER
scsi 0:0:0:0: Direct-Access ATA ST31000525SV CV11 PQ: 0 ANSI: 5
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_recover: ENTER
__ata_port_freeze: ata2 port frozen
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata2: bus reset via SRST
ata2: link is slow to respond, please be patient (ready=0)
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040005
ata_eh_thaw_port: ata2 port thawed
ata_std_postreset: ENTER
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata2: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata2: cmd 0xEC
ata_sff_hsm_move: ata2: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata2: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata2: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata2: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata2: cmd 0x27
ata_sff_hsm_move: ata2: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata2: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0407 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x007f 93==0x0000
ata2.00: ATA-8: ST31000525SV, CV11, max UDMA/133
ata2.00: 1953525168 sectors, multi 0: LBA48 NCQ (depth 31/32)
ata_dev_set_xfermode: set features - xfer mode
ata2: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x46 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata2: cmd 0xEF
ata_sff_hsm_move: ata2: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata2: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata2: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata2: cmd 0xEC
ata_sff_hsm_move: ata2: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata2: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata2: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata2: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata2: cmd 0x27
ata_sff_hsm_move: ata2: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata2: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x407f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x46
ata2.00: configured for UDMA/133
ata_eh_recover: EXIT, rc=0
ata_scsi_error: EXIT
ata_scsi_dump_cdb: CDB (2:0,0,0) 12 00 00 00 24 00 00 00 00
ata_scsiop_inq_std: ENTER
ata_scsi_dump_cdb: CDB (2:0,0,0) 12 00 00 00 60 00 00 00 00
ata_scsiop_inq_std: ENTER
scsi 1:0:0:0: Direct-Access ATA ST31000525SV CV11 PQ: 0 ANSI: 5
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_recover: ENTER
__ata_port_freeze: ata3 port frozen
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata3: bus reset via SRST
ata3: link is slow to respond, please be patient (ready=0)
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040015
ata_eh_thaw_port: ata3 port thawed
ata_std_postreset: ENTER
ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata3: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata3: cmd 0xEC
ata_sff_hsm_move: ata3: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata3: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata3: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata3: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata3: cmd 0x27
ata_sff_hsm_move: ata3: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata3: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0407 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x007f 93==0x0000
ata3.00: ATA-8: ST31000525SV, CV11, max UDMA/133
ata3.00: 1953525168 sectors, multi 0: LBA48 NCQ (depth 31/32)
ata_dev_set_xfermode: set features - xfer mode
ata3: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x46 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata3: cmd 0xEF
ata_sff_hsm_move: ata3: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata3: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata3: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata3: cmd 0xEC
ata_sff_hsm_move: ata3: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata3: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata3: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata3: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata3: cmd 0x27
ata_sff_hsm_move: ata3: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata3: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x407f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x46
ata3.00: configured for UDMA/133
ata_eh_recover: EXIT, rc=0
ata_scsi_error: EXIT
ata_scsi_dump_cdb: CDB (3:0,0,0) 12 00 00 00 24 00 00 00 00
ata_scsiop_inq_std: ENTER
ata_scsi_dump_cdb: CDB (3:0,0,0) 12 00 00 00 60 00 00 00 00
ata_scsiop_inq_std: ENTER
scsi 2:0:0:0: Direct-Access ATA ST31000525SV CV11 PQ: 0 ANSI: 5
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata4: link is slow to respond, please be patient (ready=0)
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0407 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x007f 93==0x0000
ata4.00: ATA-8: ST31000525SV, CV11, max UDMA/133
ata4.00: 1953525168 sectors, multi 0: LBA48 NCQ (depth 31/32)
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x46 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x407f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x46
ata4.00: configured for UDMA/133
ata_eh_recover: EXIT, rc=0
ata_scsi_error: EXIT
ata_scsi_dump_cdb: CDB (4:0,0,0) 12 00 00 00 24 00 00 00 00
ata_scsiop_inq_std: ENTER
ata_scsi_dump_cdb: CDB (4:0,0,0) 12 00 00 00 60 00 00 00 00
ata_scsiop_inq_std: ENTER
scsi 3:0:0:0: Direct-Access ATA ST31000525SV CV11 PQ: 0 ANSI: 5
[ra_145_82]$
[ra_145_82]$
[ra_145_82]$
[ra_145_82]$
[ra_145_82]$
[ra_145_82]$ 00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x407f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x46 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x407f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x46
ata4.00: configured for UDMA/133
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata4.00: limiting speed to UDMA/100:PIO4
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x407f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x45 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x207f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x45
ata4.00: configured for UDMA/100
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata4.00: limiting speed to UDMA/33:PIO4
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
00040015
__ata_port_freeze: ata4 port frozen
ata_sff_flush_pio_task: ENTER
ata4.00: failed to IDENTIFY (I/O error, err_mask=0x100)
ata4.00: revalidation failed (errno=-5)
ata_eh_revalidate_and_attach: EXIT rc=-5
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x207f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
00040015
__ata_port_freeze: ata4 port frozen
ata_sff_flush_pio_task: ENTER
ata4.00: failed to read native max address (err_mask=0x1)
ata4.00: HPA support seems broken, skipping HPA handling
ata4.00: revalidation failed (errno=-5)
ata_eh_revalidate_and_attach: EXIT rc=-5
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
00040015
__ata_port_freeze: ata4 port frozen
ata_sff_flush_pio_task: ENTER
------------[ cut here ]------------
WARNING: at drivers/ata/libata-sff.c:1053 0xc01702b0()
Modules linked in: sata_mv
Backtrace:
Function entered at [<c003466c>] from [<c0034784>]
r7:00000000 r6:c01702b0 r5:c0222698 r4:0000041d
Function entered at [<c003476c>] from [<c004052c>]
Function entered at [<c00404dc>] from [<c0040568>]
r8:df91930c r7:df918060 r6:df91930c r5:c02820cb r4:00000001
Function entered at [<c0040544>] from [<c01702b0>]
Function entered at [<c0170244>] from [<c0170d98>]
Function entered at [<c0170bf4>] from [<c0052200>]
r8:00000009 r7:df918060 r6:c024e320 r5:dfa2fd60 r4:decf6000
Function entered at [<c0051ff4>] from [<c0052530>]
Function entered at [<c0052364>] from [<c0056a2c>]
Function entered at [<c00569a8>] from [<c0042a28>]
r6:c0042a28 r5:c00569a8 r4:df82df10
---[ end trace 2776da609f64b4f9 ]---
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x7F)
ata_sff_hsm_move: ata4: protocol 2 task_state 4 (dev_stat 0x7F)
ata4.00: failed to IDENTIFY (I/O error, err_mask=0x2)
ata4.00: revalidation failed (errno=-5)
ata_eh_revalidate_and_attach: EXIT rc=-5
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
00040015
__ata_port_freeze: ata4 port frozen
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=1
ata4.00: failed to IDENTIFY (I/O error, err_mask=0x40)
ata4.00: revalidation failed (errno=-5)
ata4.00: limiting speed to UDMA/33:PIO3
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_xfermode: set features - xfer mode
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x3 nsect 0x42 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEF
ata_sff_hsm_move: ata4: protocol 1 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dev_set_xfermode: EXIT, err_mask=0
ata4: ata_dev_select: ENTER, device 0, wait 1
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xA0
ata_sff_exec_command: ata4: cmd 0xEC
ata_sff_hsm_move: ata4: protocol 2 task_state 2 (dev_stat 0x58)
ata_pio_sector: data read
ata_sff_hsm_move: ata4: protocol 2 task_state 3 (dev_stat 0x50)
ata_sff_hsm_move: ata4: dev 0 command complete, drv_stat 0x50
ata_sff_flush_pio_task: ENTER
ata_dump_id: 49==0x2f00 53==0x0007 63==0x0007 64==0x0003 75==0x001f
ata_dump_id: 80==0x01f0 81==0x0029 82==0x346b 83==0x7d61 84==0x4133
ata_dump_id: 88==0x047f 93==0x0000
ata_dev_set_mode: xfer_shift=12, xfer_mode=0x42
ata4.00: configured for UDMA/33
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_scsi_error: ENTER
ata_sff_flush_pio_task: ENTER
ata_eh_link_autopsy: ENTER
ata_eh_link_autopsy: EXIT
ata4: exception Emask 0x10 SAct 0x0 SErr 0x180000 action 0x6 frozen
ata4: edma_err_cause=00000020 pp_flags=00000000, SError=00180000
ata4: SError: { 10B8B Dispar }
ata_eh_recover: ENTER
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
00040055
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
00040055
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
ata4.00: disabled
ata_eh_revalidate_and_attach: ENTER
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
ata_scsi_hotplug: ENTER
ata4.00: detaching (SCSI 3:0:0:0)
ata_scsi_hotplug: EXIT
Latest News at: http://www.indigovision.com/index.php/en/news.html
On Mon, Apr 25, 2011 at 12:07:04PM +0100, Bruce Stenning wrote:
> Tejun, what does it mean to limit a sata link to UDMA/100? I thought that this
> was only for ata devices, and sata devices have the choice of 1.5Gbps, 3Gbps,
> or 6 Gbps. Is that a false assumption? Is it related to early sata devices that
> were still somewhat based on parallel ata designs?
Yeap, devices behind SATA-PATA bridge were still affected by the
transfer mode so libata tries to slow them down too along with link
speed when limiting speed due to errors. Shouldn't affect native SATA
devices.
--
tejun
Tejun wrote:
> Yeap, devices behind SATA-PATA bridge were still affected by the transfer
> mode so libata tries to slow them down too along with link speed when
> limiting speed due to errors. Shouldn't affect native SATA devices.
Thanks.
I wrote:
> 00040055
> 00040015
> __ata_port_freeze: ata4 port frozen
> ata_port_schedule_eh: port EH scheduled
> ata_eh_thaw_port: ata4 port thawed
> ata_std_postreset: ENTER
> ata4: SATA link down (SStatus 0 SControl 310)
> ata_std_postreset: EXIT
> ata_eh_revalidate_and_attach: ENTER
> ata_eh_revalidate_and_attach: EXIT rc=-5
> ata4.00: disabled
> ata_eh_revalidate_and_attach: ENTER
> ata_eh_recover: EXIT, rc=0
> ata4: EH complete
> ata_scsi_error: EXIT
> ata_scsi_hotplug: ENTER
> ata4.00: detaching (SCSI 3:0:0:0)
> ata_scsi_hotplug: EXIT
Okay, so the ata_eh_thaw_port has raced (and won) against whatever was in the
process of masking off the irq (the __ata_port_freeze?), which then completes
leaving libata/sata_mv thinking the port is thawed while no further irqs get
generated.
Could ata_port_freeze or __ata_port_freeze (which don't claim the ap's lock)
have been invoked and then slept while ata_eh_thaw_port runs?
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
Hello,
I haven't followed the trace but,
> > __ata_port_freeze: ata4 port frozen
> > ata_port_schedule_eh: port EH scheduled
> > ata_eh_thaw_port: ata4 port thawed
> > ata_std_postreset: ENTER
> > ata4: SATA link down (SStatus 0 SControl 310)
> > ata_std_postreset: EXIT
> > ata_eh_revalidate_and_attach: ENTER
> > ata_eh_revalidate_and_attach: EXIT rc=-5
> > ata4.00: disabled
> > ata_eh_revalidate_and_attach: ENTER
> > ata_eh_recover: EXIT, rc=0
> > ata4: EH complete
> > ata_scsi_error: EXIT
> > ata_scsi_hotplug: ENTER
> > ata4.00: detaching (SCSI 3:0:0:0)
> > ata_scsi_hotplug: EXIT
>
> Okay, so the ata_eh_thaw_port has raced (and won) against whatever was in the
> process of masking off the irq (the __ata_port_freeze?), which then completes
> leaving libata/sata_mv thinking the port is thawed while no further irqs get
> generated.
>
> Could ata_port_freeze or __ata_port_freeze (which don't claim the ap's lock)
> have been invoked and then slept while ata_eh_thaw_port runs?
ata4 is reporting link down and the device is detached and port
disabled afterwards. Doesn't seem to have much to do with
freezing/thawing?
--
tejun
Tejun wrote:
> ata4 is reporting link down and the device is detached and port
> disabled afterwards. Doesn't seem to have much to do with
> freezing/thawing?
After all processing of a normal unplug event has completed, the port is left
thawed (and the irq enabled) to allow future hotplug events on this port to be
actioned. In the case of the port lockups that I have seen the port appears
to be left frozen, with the irq disabled, and I am hypothesising that this is
due to a race between the freeze and the thaw.
Below is some additional tracing leading up to a port lockup, with some more
DPRINTK statements added. The port freeze appears to be happening after the
port thaw. The irq mask writes that are output by mv_set_main_irq_mask seem
to show the irqs left masked off.
...
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
mv_set_main_irq_mask: skipped write in mv_set_main_irq_mask: 00040015, 00040015
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
mv_eh_thaw: ENTER
00040055
mv_eh_thaw: EXIT
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
00040015
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_revalidate_and_attach: EXIT rc=-5
ata4.00: disabled
ata_eh_revalidate_and_attach: ENTER
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
ata_scsi_hotplug: ENTER
ata4.00: detaching (SCSI 3:0:0:0)
ata_scsi_hotplug: EXIT
The port is unresponsive at this point.
And another lockup, with tracing showing entering and leaving mv_eh_freeze:
...
ata_sff_tf_load: hob: feat 0x0 nsect 0x0, lba 0x0 0x0 0x0
ata_sff_tf_load: feat 0x0 nsect 0x0 lba 0x0 0x0 0x0
ata_sff_tf_load: device 0xE0
ata_sff_exec_command: ata4: cmd 0x27
mv_eh_freeze: ENTER
00040015
mv_eh_freeze: EXIT
__ata_port_freeze: ata4 port frozen
ata_sff_flush_pio_task: ENTER
ata4.00: failed to read native max address (err_mask=0x1)
ata4.00: HPA support seems broken, skipping HPA handling
ata4.00: revalidation failed (errno=-5)
ata4.00: disabled
mv_eh_freeze: ENTER
mv_set_main_irq_mask: skipped write in mv_set_main_irq_mask: 00040015, 00040015
mv_eh_freeze: EXIT
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
sata_link_hardreset: EXIT, rc=0
ata_sff_softreset: ENTER
ata_sff_softreset: about to softreset, devmask=1
ata_bus_softreset: ata4: bus reset via SRST
ata_dev_classify: found ATA device by sig
ata_sff_softreset: EXIT, classes[0]=1 [1]=0
mv_eh_thaw: ENTER
00040055
mv_eh_thaw: EXIT
mv_eh_freeze: ENTER
00040015
mv_eh_freeze: EXIT
__ata_port_freeze: ata4 port frozen
ata_port_schedule_eh: port EH scheduled
ata_eh_thaw_port: ata4 port thawed
ata_std_postreset: ENTER
ata4: SATA link down (SStatus 0 SControl 310)
ata_std_postreset: EXIT
ata_eh_revalidate_and_attach: ENTER
ata_eh_recover: EXIT, rc=0
ata4: EH complete
ata_scsi_error: EXIT
ata_scsi_hotplug: ENTER
ata4.00: detaching (SCSI 3:0:0:0)
ata_scsi_hotplug: EXIT
The port is unresponsive at this point.
The output shows "ata_eh_thaw_port: ata4 port thawed" after the
"__ata_port_freeze: ata4 port frozen", but the tracing suggests that the actual
work enabling the irqs has been carried out before the irqs are subsequently
disabled.
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
On Tue, Apr 26, 2011 at 02:13:22PM +0100, Bruce Stenning wrote:
> Tejun wrote:
> > ata4 is reporting link down and the device is detached and port
> > disabled afterwards. Doesn't seem to have much to do with
> > freezing/thawing?
>
> After all processing of a normal unplug event has completed, the port is left
> thawed (and the irq enabled) to allow future hotplug events on this port to be
> actioned. In the case of the port lockups that I have seen the port appears
> to be left frozen, with the irq disabled, and I am hypothesising that this is
> due to a race between the freeze and the thaw.
>
> Below is some additional tracing leading up to a port lockup, with some more
> DPRINTK statements added. The port freeze appears to be happening after the
> port thaw. The irq mask writes that are output by mv_set_main_irq_mask seem
> to show the irqs left masked off.
Does the following patch resolve the problem?
Thanks.
diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index 88cd22f..73f0589 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -2802,19 +2802,6 @@ int ata_eh_reset(struct ata_link *link, int classify,
}
/*
- * Some controllers can't be frozen very well and may set
- * spuruious error conditions during reset. Clear accumulated
- * error information. As reset is the final recovery action,
- * nothing is lost by doing this.
- */
- spin_lock_irqsave(link->ap->lock, flags);
- memset(&link->eh_info, 0, sizeof(link->eh_info));
- if (slave)
- memset(&slave->eh_info, 0, sizeof(link->eh_info));
- ap->pflags &= ~ATA_PFLAG_EH_PENDING;
- spin_unlock_irqrestore(link->ap->lock, flags);
-
- /*
* Make sure onlineness and classification result correspond.
* Hotplug could have happened during reset and some
* controllers fail to wait while a drive is spinning up after
Tejun wrote:
> Does the following patch resolve the problem?
>
> Thanks.
I have applied that patch, keeping Mark's mv_set_main_irq_mask spinlock patch
in place. I would not like to commit absolutely, for obvious reasons, but I
have abused the port considerably and have not been able to coax it into
locking up.
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
Hello,
On Tue, Apr 26, 2011 at 04:41:25PM +0100, Bruce Stenning wrote:
> Tejun wrote:
> > Does the following patch resolve the problem?
>
> I have applied that patch, keeping Mark's mv_set_main_irq_mask spinlock patch
> in place. I would not like to commit absolutely, for obvious reasons, but I
> have abused the port considerably and have not been able to coax it into
> locking up.
Yeah, it makes sense. Hmm... it seems I wasn't thinking straight when
I added that work around. Not sure how to fix it properly at this
moment. I'll think about it. Can you please keep me posted if you
find something while testing?
Thanks.
--
tejun
> Yeah, it makes sense. Hmm... it seems I wasn't thinking straight when
> I added that work around. Not sure how to fix it properly at this
> moment. I'll think about it. Can you please keep me posted if you
> find something while testing?
I'm away for two and a bit weeks so I'm not sure what progress (if any)
I will make during that time. But yes, I shall certainly keep you posted
as soon as I find anything else. Thank you very much for your inputs.
Cheers,
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
On 11-04-25 07:30 AM, Tejun Heo wrote:
> On Mon, Apr 25, 2011 at 12:07:04PM +0100, Bruce Stenning wrote:
>> Tejun, what does it mean to limit a sata link to UDMA/100? I thought that this
>> was only for ata devices, and sata devices have the choice of 1.5Gbps, 3Gbps,
>> or 6 Gbps. Is that a false assumption? Is it related to early sata devices that
>> were still somewhat based on parallel ata designs?
>
> Yeap, devices behind SATA-PATA bridge were still affected by the
> transfer mode so libata tries to slow them down too along with link
> speed when limiting speed due to errors. Shouldn't affect native SATA
> devices.
Yeah, what he said. :)
First generation SATA devices were merely PATA transports
with a SATA-to-PATA converter chip onboard. Some of those
require that we set the transfer modes.
Ditto for various more modern setups, where CF-cards, PATA drives,
and other weirdos are connected through a discrete SATA bridge device.
Cheers
On 11-04-26 11:41 AM, Bruce Stenning wrote:
> Tejun wrote:
>> Does the following patch resolve the problem?
>>
>> Thanks.
>
> I have applied that patch, keeping Mark's mv_set_main_irq_mask spinlock patch
> in place. I would not like to commit absolutely, for obvious reasons, but I
> have abused the port considerably and have not been able to coax it into
> locking up.
I'm thinking perhaps I should dust off that spinlock patch
and send something more proper like that upstream.
With that mask register shared among the ports, it is really
hard to keep track of when we're locked and when not.
So having a lock just for the shared part of the chip
has got to be a less error-prone way to do it.
I'll pull down a recent -git to patch against first.
Cheers
Hello,
On Tue, Apr 26, 2011 at 05:05:45PM +0100, Bruce Stenning wrote:
> > Yeah, it makes sense. Hmm... it seems I wasn't thinking straight when
> > I added that work around. Not sure how to fix it properly at this
> > moment. I'll think about it. Can you please keep me posted if you
> > find something while testing?
>
> I'm away for two and a bit weeks so I'm not sure what progress (if any)
> I will make during that time. But yes, I shall certainly keep you posted
> as soon as I find anything else. Thank you very much for your inputs.
So, here's the patch which should fix the problem you're seeing and
doesn't break the controllers which generate spurious hotplug events
during reset. Please test this when you come back and let me know the
result.
Thank you.
diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index f26f2fe..a57845d 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -2802,10 +2802,11 @@ int ata_eh_reset(struct ata_link *link, int classify,
}
/*
- * Some controllers can't be frozen very well and may set
- * spuruious error conditions during reset. Clear accumulated
- * error information. As reset is the final recovery action,
- * nothing is lost by doing this.
+ * Some controllers can't be frozen very well and may set spuruious
+ * error conditions during reset. Clear accumulated error
+ * information and re-thaw the port if frozen. As reset is the
+ * final recovery action and we cross check link onlineness against
+ * device classification later, no hotplug event is lost by this.
*/
spin_lock_irqsave(link->ap->lock, flags);
memset(&link->eh_info, 0, sizeof(link->eh_info));
@@ -2814,6 +2815,9 @@ int ata_eh_reset(struct ata_link *link, int classify,
ap->pflags &= ~ATA_PFLAG_EH_PENDING;
spin_unlock_irqrestore(link->ap->lock, flags);
+ if (ap->pflags & ATA_PFLAG_FROZEN)
+ ata_eh_thaw_port(ap);
+
/*
* Make sure onlineness and classification result correspond.
* Hotplug could have happened during reset and some
Hi Tejun,
> So, here's the patch which should fix the problem you're seeing and
> doesn't break the controllers which generate spurious hotplug events
> during reset. Please test this when you come back and let me know the
> result.
I have tested this patch out a fair amount, and it seemed to make things
much more reliable, but I have managed to lock up the port again this
afternoon. Below is some tracing showing ata4 being frozen and not thawed:
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
ata4: COMRESET failed (errno=-32)
sata_link_hardreset: EXIT, rc=-32
ata4: reset failed (errno=-32), retrying in 33 secs
__ata_port_freeze: ata4 port frozen
ata4: hard resetting link
sata_link_hardreset: ENTER
ata4: COMRESET failed (errno=-32)
sata_link_hardreset: EXIT, rc=-32
ata4: reset failed, giving up
ata_eh_recover: EXIT, rc=-32
ata4.00: disabled
ata4: EH complete
ata_scsi_error: EXIT
The IRQ for that port is masked off afterwards.
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
Hello, sorry about the long delay.
On Tue, May 17, 2011 at 04:30:20PM +0100, Bruce Stenning wrote:
> __ata_port_freeze: ata4 port frozen
> ata4: hard resetting link
> sata_link_hardreset: ENTER
> ata4: COMRESET failed (errno=-32)
> sata_link_hardreset: EXIT, rc=-32
> ata4: reset failed (errno=-32), retrying in 33 secs
> __ata_port_freeze: ata4 port frozen
> ata4: hard resetting link
> sata_link_hardreset: ENTER
> ata4: COMRESET failed (errno=-32)
> sata_link_hardreset: EXIT, rc=-32
> ata4: reset failed, giving up
> ata_eh_recover: EXIT, rc=-32
> ata4.00: disabled
> ata4: EH complete
> ata_scsi_error: EXIT
>
> The IRQ for that port is masked off afterwards.
This is a different issue. libata EH plugs the port if reset fails
repeatedly. This behavior was implemented to avoid causing continuous
resets on a port in case it has flaky PHY state reporting; however, it
seems to cause more trouble than fixing issues - ie. plugging in a
broken device may end up plugging the port even after the offending
device is removed until manual rescan or reboot. I've been pondering
about changing the behavior like the following.
diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index dfb6e9d..05797fe 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -2885,8 +2885,17 @@ int ata_eh_reset(struct ata_link *link, int classify,
sata_scr_read(link, SCR_STATUS, &sstatus))
rc = -ERESTART;
- if (rc == -ERESTART || try >= max_tries)
+ if (rc == -ERESTART || try >= max_tries) {
+ /*
+ * Thaw host port even if reset failed, so that the port
+ * can be retried on the next phy event. This risks
+ * repeated EH runs but seems to be a better tradeoff than
+ * shutting down a port after a botched hotplug attempt.
+ */
+ if (ata_is_host_link(link))
+ ata_eh_thaw_port(ap);
goto out;
+ }
now = jiffies;
if (time_before(now, deadline)) {
> This is a different issue. libata EH plugs the port if reset fails
> repeatedly. This behavior was implemented to avoid causing continuous
> resets on a port in case it has flaky PHY state reporting; however, it
> seems to cause more trouble than fixing issues - ie. plugging in a
> broken device may end up plugging the port even after the offending
> device is removed until manual rescan or reboot. I've been pondering
> about changing the behavior like the following.
Thanks for the explanation, Tejun, and for sending those changes upstream.
I shall incorporate these patches into my kernel and keep you informed as
to how they behave.
Mark, did you get a chance to clean up the sata_mv spinlock addition in
mv_set_main_irq_mask?
Many Thanks,
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
On 11-05-25 09:36 AM, Bruce Stenning wrote:
>> This is a different issue. libata EH plugs the port if reset fails
>> repeatedly. This behavior was implemented to avoid causing continuous
>> resets on a port in case it has flaky PHY state reporting; however, it
>> seems to cause more trouble than fixing issues - ie. plugging in a
>> broken device may end up plugging the port even after the offending
>> device is removed until manual rescan or reboot. I've been pondering
>> about changing the behavior like the following.
>
> Thanks for the explanation, Tejun, and for sending those changes upstream.
> I shall incorporate these patches into my kernel and keep you informed as
> to how they behave.
>
> Mark, did you get a chance to clean up the sata_mv spinlock addition in
> mv_set_main_irq_mask?
Not yet. I've been waiting to hear back from you as to
whether they visibly fix anything or not.
> > Mark, did you get a chance to clean up the sata_mv spinlock addition in
> > mv_set_main_irq_mask?
>
> Not yet. I've been waiting to hear back from you as to
> whether they visibly fix anything or not.
Having now tested with Tejun's two patches and without the spinlock in
mv_set_main_irq_mask for a reasonable time, the hotplug seems to be very
reliable. So I think it's probably best to leave the spinlock out and
continue to observe the behaviour with further testing.
Thanks,
Bruce.
Latest News at: http://www.indigovision.com/index.php/en/news.html
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
On 11-05-30 09:07 AM, Bruce Stenning wrote:
>>> Mark, did you get a chance to clean up the sata_mv spinlock addition in
>>> mv_set_main_irq_mask?
>>
>> Not yet. I've been waiting to hear back from you as to
>> whether they visibly fix anything or not.
>
> Having now tested with Tejun's two patches and without the spinlock in
> mv_set_main_irq_mask for a reasonable time, the hotplug seems to be very
> reliable. So I think it's probably best to leave the spinlock out and
> continue to observe the behaviour with further testing.
Peachy. I'll have another look at some point -- I think I thought
the spinlock was still needed for ATAPI under some conditions.
Gotta look closer to make sure.
Thanks.
On 11-05-25 05:41 AM, Tejun Heo wrote:
> Hello, sorry about the long delay.
>
> On Tue, May 17, 2011 at 04:30:20PM +0100, Bruce Stenning wrote:
>> __ata_port_freeze: ata4 port frozen
>> ata4: hard resetting link
>> sata_link_hardreset: ENTER
>> ata4: COMRESET failed (errno=-32)
>> sata_link_hardreset: EXIT, rc=-32
>> ata4: reset failed (errno=-32), retrying in 33 secs
>> __ata_port_freeze: ata4 port frozen
>> ata4: hard resetting link
>> sata_link_hardreset: ENTER
>> ata4: COMRESET failed (errno=-32)
>> sata_link_hardreset: EXIT, rc=-32
>> ata4: reset failed, giving up
>> ata_eh_recover: EXIT, rc=-32
>> ata4.00: disabled
>> ata4: EH complete
>> ata_scsi_error: EXIT
>>
>> The IRQ for that port is masked off afterwards.
>
> This is a different issue. libata EH plugs the port if reset fails
> repeatedly. This behavior was implemented to avoid causing continuous
> resets on a port in case it has flaky PHY state reporting; however, it
> seems to cause more trouble than fixing issues - ie. plugging in a
> broken device may end up plugging the port even after the offending
> device is removed until manual rescan or reboot. I've been pondering
> about changing the behavior like the following.
>
> diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
> index dfb6e9d..05797fe 100644
> --- a/drivers/ata/libata-eh.c
> +++ b/drivers/ata/libata-eh.c
> @@ -2885,8 +2885,17 @@ int ata_eh_reset(struct ata_link *link, int classify,
> sata_scr_read(link, SCR_STATUS, &sstatus))
> rc = -ERESTART;
>
> - if (rc == -ERESTART || try >= max_tries)
> + if (rc == -ERESTART || try >= max_tries) {
> + /*
> + * Thaw host port even if reset failed, so that the port
> + * can be retried on the next phy event. This risks
> + * repeated EH runs but seems to be a better tradeoff than
> + * shutting down a port after a botched hotplug attempt.
> + */
> + if (ata_is_host_link(link))
> + ata_eh_thaw_port(ap);
> goto out;
> + }
>
> now = jiffies;
> if (time_before(now, deadline)) {
Tejun, did this ever go upstream and to -stable ??
I'm asking because I see the same issue with other SATA controllers,
in particular with sata_sil boards. Hot plug generally works _once_
per port, and then stops working.
Hello,
(cc'ing Jeff)
On Fri, Jun 10, 2011 at 08:28:51AM -0400, Mark Lord wrote:
> Tejun, did this ever go upstream and to -stable ??
> I'm asking because I see the same issue with other SATA controllers,
> in particular with sata_sil boards. Hot plug generally works _once_
> per port, and then stops working.
The patch is still pending,
http://article.gmane.org/gmane.linux.ide/49613
I don't think it would be wise to include the patch for -stable tho.
It's not a regression fix and has some possibility of introducing
regressions, so....
Thanks.
--
tejun
On 11-06-10 10:01 AM, Tejun Heo wrote:
> Hello,
>
> (cc'ing Jeff)
>
> On Fri, Jun 10, 2011 at 08:28:51AM -0400, Mark Lord wrote:
>> Tejun, did this ever go upstream and to -stable ??
>> I'm asking because I see the same issue with other SATA controllers,
>> in particular with sata_sil boards. Hot plug generally works _once_
>> per port, and then stops working.
>
> The patch is still pending,
>
> http://article.gmane.org/gmane.linux.ide/49613
>
> I don't think it would be wise to include the patch for -stable tho.
> It's not a regression fix and has some possibility of introducing
> regressions, so....
Not a regression fix? Excuse me?
SATA hotplug always used to work fine,
and is more or less essential to reboot-free operations.
Cheers
On 06/10/2011 01:32 PM, Mark Lord wrote:
> On 11-06-10 10:01 AM, Tejun Heo wrote:
>> Hello,
>>
>> (cc'ing Jeff)
>>
>> On Fri, Jun 10, 2011 at 08:28:51AM -0400, Mark Lord wrote:
>>> Tejun, did this ever go upstream and to -stable ??
>>> I'm asking because I see the same issue with other SATA controllers,
>>> in particular with sata_sil boards. Hot plug generally works _once_
>>> per port, and then stops working.
>>
>> The patch is still pending,
>>
>> http://article.gmane.org/gmane.linux.ide/49613
>>
>> I don't think it would be wise to include the patch for -stable tho.
>> It's not a regression fix and has some possibility of introducing
>> regressions, so....
>
> Not a regression fix? Excuse me?
> SATA hotplug always used to work fine,
> and is more or less essential to reboot-free operations.
I can move it from #upstream (linux-next) to #upstream-fixes, if we feel
it is sufficient urgent. It seemed like it needed more testing, but
maybe the best way to do that is #upstream-fixes?
Was mainly a -rc question, to me.
Jeff
On 11-06-10 01:39 PM, Jeff Garzik wrote:
> On 06/10/2011 01:32 PM, Mark Lord wrote:
>> On 11-06-10 10:01 AM, Tejun Heo wrote:
>>> Hello,
>>>
>>> (cc'ing Jeff)
>>>
>>> On Fri, Jun 10, 2011 at 08:28:51AM -0400, Mark Lord wrote:
>>>> Tejun, did this ever go upstream and to -stable ??
>>>> I'm asking because I see the same issue with other SATA controllers,
>>>> in particular with sata_sil boards. Hot plug generally works _once_
>>>> per port, and then stops working.
>>>
>>> The patch is still pending,
>>>
>>> http://article.gmane.org/gmane.linux.ide/49613
>>>
>>> I don't think it would be wise to include the patch for -stable tho.
>>> It's not a regression fix and has some possibility of introducing
>>> regressions, so....
>>
>> Not a regression fix? Excuse me?
>> SATA hotplug always used to work fine,
>> and is more or less essential to reboot-free operations.
>
> I can move it from #upstream (linux-next) to #upstream-fixes, if we feel it is
> sufficient urgent. It seemed like it needed more testing, but maybe the best
> way to do that is #upstream-fixes?
>
> Was mainly a -rc question, to me.
Well, it's not getting any testing sitting outside of the kernel right now.
Cheers
On 06/10/2011 04:49 PM, Mark Lord wrote:
> Well, it's not getting any testing sitting outside of the kernel right now.
It gets whatever testing linux-next gets...
Jeff
On Fri, Jun 10, 2011 at 01:32:22PM -0400, Mark Lord wrote:
> > I don't think it would be wise to include the patch for -stable tho.
> > It's not a regression fix and has some possibility of introducing
> > regressions, so....
>
> Not a regression fix? Excuse me?
> SATA hotplug always used to work fine,
> and is more or less essential to reboot-free operations.
There are two separate patches. One is a fix which got pushed to
Linus by Jeff early yesterday. The other changes behavior which has
been like that since the beginning of EH. The former is marked
properly w/ -stable. The latter shouldn't be in -stable.
Thanks.
--
tejun
On 11-06-11 08:19 AM, Tejun Heo wrote:
> On Fri, Jun 10, 2011 at 01:32:22PM -0400, Mark Lord wrote:
>>> I don't think it would be wise to include the patch for -stable tho.
>>> It's not a regression fix and has some possibility of introducing
>>> regressions, so....
>>
>> Not a regression fix? Excuse me?
>> SATA hotplug always used to work fine,
>> and is more or less essential to reboot-free operations.
>
> There are two separate patches. One is a fix which got pushed to
> Linus by Jeff early yesterday. The other changes behavior which has
> been like that since the beginning of EH. The former is marked
> properly w/ -stable. The latter shouldn't be in -stable.
Peachy. Got links for each of those?
I may try them with the sata_sil board that was having issues earlier.
Cheers
Hello,
On Sun, Jun 12, 2011 at 01:10:35PM -0400, Mark Lord wrote:
> On 11-06-11 08:19 AM, Tejun Heo wrote:
> > On Fri, Jun 10, 2011 at 01:32:22PM -0400, Mark Lord wrote:
> >>> I don't think it would be wise to include the patch for -stable tho.
> >>> It's not a regression fix and has some possibility of introducing
> >>> regressions, so....
> >>
> >> Not a regression fix? Excuse me?
> >> SATA hotplug always used to work fine,
> >> and is more or less essential to reboot-free operations.
> >
> > There are two separate patches. One is a fix which got pushed to
> > Linus by Jeff early yesterday. The other changes behavior which has
> > been like that since the beginning of EH. The former is marked
> > properly w/ -stable. The latter shouldn't be in -stable.
>
> Peachy. Got links for each of those?
> I may try them with the sata_sil board that was having issues earlier.
The fix is
http://article.gmane.org/gmane.linux.ide/49615
and the behavior change is
http://article.gmane.org/gmane.linux.ide/49613
--
tejun