Spinup command fails on WD3200JS

Spinup command fails on WD3200JS

[Ryan Power]

Hi.
I've run into a problem with the lastest kernel (2.6.22.1) and a drive set 
to spinup on set_features.

hdparm reports:
/dev/sdf:

ATA device, with non-removable media
powers-up in standby; SET FEATURES subcmd spins-up.
         Model Number:       WDC WD3200JS-57PDB0
         Serial Number:      X
         Firmware Revision:  21.00M21
...
Commands/features:
         Enabled Supported:
            *    Power-Up In Standby feature set
            *    SET_FEATURES required to spinup after power up
...

I get the following messages when booting:
Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 
SControl 300)
Jul 12 23:47:22 sysreset kernel: ata6.00: ATA-7: WDC WD3200JS-57PDB0, 
21.00M21, max UDMA/133
Jul 12 23:47:22 sysreset kernel: ata6.00: 625142448 sectors, multi 0: LBA48 
NCQ (depth 1)
Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP 
failed, err_mask=0x1)
Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
Jul 12 23:47:22 sysreset kernel: ata6: failed to recover some devices, 
retrying in 5 secs
Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 
SControl 300)
Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP 
failed, err_mask=0x1)
Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
Jul 12 23:47:22 sysreset kernel: ata6.00: limiting speed to UDMA/133:PIO3
Jul 12 23:47:22 sysreset kernel: ata6: failed to recover some devices, 
retrying in 5 secs
Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 
SControl 300)
Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP 
failed, err_mask=0x1)
Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
Jul 12 23:47:22 sysreset kernel: ata6.00: disabled

The interesting thing is that after displaying that, the drive has in fact 
spun up.  I'm not sure why it's getting an error returned, but chaning the 
err_mask line to read "if (err_mask && err_mask != 0x01)" corrects the 
problem and the drive spins up and ID's normally:
ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata6.00: ATA-7: WDC WD3200JS-57PDB0, 21.00M21, max UDMA/133
ata6.00: 625142448 sectors, multi 0: LBA48 NCQ (depth 1)
ata6.00: configured for UDMA/133

If you'd like me to do any more testing or need more information from me 
please let me know.
Thank you.

-Ryan Power

Re: Spinup command fails on WD3200JS

[Tejun Heo]

Mark?

Ryan Power wrote:
> Hi.
> I've run into a problem with the lastest kernel (2.6.22.1) and a drive
> set to spinup on set_features.
> 
> hdparm reports:
> /dev/sdf:
> 
> ATA device, with non-removable media
> powers-up in standby; SET FEATURES subcmd spins-up.
>         Model Number:       WDC WD3200JS-57PDB0
>         Serial Number:      X
>         Firmware Revision:  21.00M21
> ...
> Commands/features:
>         Enabled Supported:
>            *    Power-Up In Standby feature set
>            *    SET_FEATURES required to spinup after power up
> ...
> 
> I get the following messages when booting:
> Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus
> 113 SControl 300)
> Jul 12 23:47:22 sysreset kernel: ata6.00: ATA-7: WDC WD3200JS-57PDB0,
> 21.00M21, max UDMA/133
> Jul 12 23:47:22 sysreset kernel: ata6.00: 625142448 sectors, multi 0:
> LBA48 NCQ (depth 1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP
> failed, err_mask=0x1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
> Jul 12 23:47:22 sysreset kernel: ata6: failed to recover some devices,
> retrying in 5 secs
> Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus
> 113 SControl 300)
> Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP
> failed, err_mask=0x1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
> Jul 12 23:47:22 sysreset kernel: ata6.00: limiting speed to UDMA/133:PIO3
> Jul 12 23:47:22 sysreset kernel: ata6: failed to recover some devices,
> retrying in 5 secs
> Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus
> 113 SControl 300)
> Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP
> failed, err_mask=0x1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
> Jul 12 23:47:22 sysreset kernel: ata6.00: disabled
> 
> The interesting thing is that after displaying that, the drive has in
> fact spun up.  I'm not sure why it's getting an error returned, but
> chaning the err_mask line to read "if (err_mask && err_mask != 0x01)"
> corrects the problem and the drive spins up and ID's normally:
> ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> ata6.00: ATA-7: WDC WD3200JS-57PDB0, 21.00M21, max UDMA/133
> ata6.00: 625142448 sectors, multi 0: LBA48 NCQ (depth 1)
> ata6.00: configured for UDMA/133
> 
> If you'd like me to do any more testing or need more information from me
> please let me know.
> Thank you.


-- 
tejun

Re: Spinup command fails on WD3200JS

[Mark Lord]

> Hi.
> I've run into a problem with the lastest kernel (2.6.22.1) and a drive set to spinup on set_features.
..
> ATA device, with non-removable media
> powers-up in standby; SET FEATURES subcmd spins-up.
>         Model Number:       WDC WD3200JS-57PDB0
>         Serial Number:      X
>         Firmware Revision:  21.00M21
> ...
>            *    Power-Up In Standby feature set
>            *    SET_FEATURES required to spinup after power up
> ...
> Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> Jul 12 23:47:22 sysreset kernel: ata6.00: ATA-7: WDC WD3200JS-57PDB0, 21.00M21, max UDMA/133
> Jul 12 23:47:22 sysreset kernel: ata6.00: 625142448 sectors, multi 0: LBA48 NCQ (depth 1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP failed, err_mask=0x1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
> Jul 12 23:47:22 sysreset kernel: ata6: failed to recover some devices, retrying in 5 secs
> Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP failed, err_mask=0x1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
> Jul 12 23:47:22 sysreset kernel: ata6.00: limiting speed to UDMA/133:PIO3
> Jul 12 23:47:22 sysreset kernel: ata6: failed to recover some devices, retrying in 5 secs
> Jul 12 23:47:22 sysreset kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> Jul 12 23:47:22 sysreset kernel: ata6.00: failed to IDENTIFY (SPINUP failed, err_mask=0x1)
> Jul 12 23:47:22 sysreset kernel: ata6.00: revalidation failed (errno=-5)
> Jul 12 23:47:22 sysreset kernel: ata6.00: disabled

It would be handy to see those messages again with real timestamps on them.
Ryan, could you add CONFIG_PRINTK_TIME=y into your .config and rebuild/retry ?

> The interesting thing is that after displaying that, the drive has in fact spun up.
> I'm not sure why it's getting an error returned, but chaning the err_mask line
> to read "if (err_mask && err_mask != 0x01)" corrects the problem and the drive
> spins up and ID's normally:

Yeah, I believe that for WD drives.  Their firmware has *always* been peculiar.
In fact, the WD Raptor drives I used to have here had similar, though not identical,
problems with the "jumper-enabled" power-on-in-standby version.  I never did figure
those ones out.

But yes, perhaps your suggestion of just ignoring the device's response
may be best.  Are you sure it spins up on the very first attempt?
Also, could you add this printk() line to just before your err_mask hack:

   printk("id[2]=0x%04x\n", id[2]);

If we see 0x738c reported from that, then we *know* we should just continue
rather than err'ing out as is presently done.

Thanks

Re: Spinup command fails on WD3200JS

[Ryan Power]

Here's the section with the modifications you requested:
[    2.212000] sata_sil 0000:01:08.0: version 2.2
[    2.216000] ACPI: PCI Interrupt Link [APC3] enabled at IRQ 18
[    2.216000] ACPI: PCI Interrupt 0000:01:08.0[A] -> Link [APC3] -> GSI 18 
(level, low) -> IRQ 16
[    2.216000] PCI: Setting latency timer of device 0000:01:08.0 to 64
[    2.216000] scsi0 : sata_sil
[    2.216000] scsi1 : sata_sil
[    2.216000] ata1: SATA max UDMA/100 cmd 0xf880c080 ctl 0xf880c08a bmdma 
0xf880c000 irq 16
[    2.216000] ata2: SATA max UDMA/100 cmd 0xf880c0c0 ctl 0xf880c0ca bmdma 
0xf880c008 irq 16
[    2.684000] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[    2.692000] ata1.00: ATA-7: Maxtor 6L320S0, BACE1G20, max UDMA/133
[    2.692000] ata1.00: 625142448 sectors, multi 16: LBA48 NCQ (depth 0/32)
[    2.708000] ata1.00: configured for UDMA/100
[    3.176000] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[   11.020000] id[2]=0x37c8
[   11.036000] ata2.00: ATA-7: WDC WD3200JS-57PDB0, 21.00M21, max UDMA/133
[   11.036000] ata2.00: 625142448 sectors, multi 0: LBA48 NCQ (depth 0/1)
[   11.052000] id[2]=0x738c
[   11.052000] ata2.00: failed to IDENTIFY (SPINUP failed, err_mask=0x1)
[   11.052000] ata2.00: revalidation failed (errno=-5)
[   11.052000] ata2: failed to recover some devices, retrying in 5 secs
[   16.532000] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[   16.540000] id[2]=0x738c
[   16.540000] ata2.00: failed to IDENTIFY (SPINUP failed, err_mask=0x1)
[   16.540000] ata2.00: revalidation failed (errno=-5)
[   16.540000] ata2.00: limiting speed to UDMA/100:PIO3
[   16.540000] ata2: failed to recover some devices, retrying in 5 secs
[   22.020000] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[   22.028000] id[2]=0x738c
[   22.028000] ata2.00: failed to IDENTIFY (SPINUP failed, err_mask=0x1)
[   22.028000] ata2.00: revalidation failed (errno=-5)
[   22.028000] ata2.00: disabled
[   22.532000] scsi 0:0:0:0: Direct-Access     ATA      Maxtor 
6L320S0   BACE PQ: 0 ANSI: 5
[   22.532000] sd 0:0:0:0: [sda] 625142448 512-byte hardware sectors 
(320073 MB)
[   22.532000] sd 0:0:0:0: [sda] Write Protect is off
[   22.532000] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00

I'm positive that it's spun up after the first command is execicuted.  I 
can hear the drive spinup, and doing a soft reboot allows it to be detected 
normally.
The same section with "if (err_mask && id[2] != 0x738c)" in place of the 
previous modification:
[    2.216000] scsi0 : sata_sil
[    2.216000] scsi1 : sata_sil
[    2.216000] ata1: SATA max UDMA/100 cmd 0xf880c080 ctl 0xf880c08a bmdma 
0xf880c000 irq 16
[    2.216000] ata2: SATA max UDMA/100 cmd 0xf880c0c0 ctl 0xf880c0ca bmdma 
0xf880c008 irq 16
[    2.684000] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[    2.692000] ata1.00: ATA-7: Maxtor 6L320S0, BACE1G20, max UDMA/133
[    2.692000] ata1.00: 625142448 sectors, multi 16: LBA48 NCQ (depth 0/32)
[    2.708000] ata1.00: configured for UDMA/100
[    3.176000] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[   10.944000] id[2]=0x37c8
[   10.964000] ata2.00: ATA-7: WDC WD3200JS-57PDB0, 21.00M21, max UDMA/133
[   10.964000] ata2.00: 625142448 sectors, multi 0: LBA48 NCQ (depth 0/1)
[   10.972000] id[2]=0x738c
[   10.972000] ata2.00: configured for UDMA/100

I'm uncertain as to which would be better to do; ignoring the error or 
looking for the STBY_ID value.

Thanks.
-Ryan Power


At 06:53 AM 7/13/2007, Mark Lord wrote:
>>Hi.
>>I've run into a problem with the lastest kernel (2.6.22.1) and a drive 
>>set to spinup on set_features.
>..
>
>It would be handy to see those messages again with real timestamps on them.
>Ryan, could you add CONFIG_PRINTK_TIME=y into your .config and rebuild/retry ?
>
>>The interesting thing is that after displaying that, the drive has in 
>>fact spun up.
>>I'm not sure why it's getting an error returned, but chaning the err_mask 
>>line
>>to read "if (err_mask && err_mask != 0x01)" corrects the problem and the 
>>drive
>>spins up and ID's normally:
>
>Yeah, I believe that for WD drives.  Their firmware has *always* been 
>peculiar.
>In fact, the WD Raptor drives I used to have here had similar, though not 
>identical,
>problems with the "jumper-enabled" power-on-in-standby version.  I never 
>did figure
>those ones out.
>
>But yes, perhaps your suggestion of just ignoring the device's response
>may be best.  Are you sure it spins up on the very first attempt?
>Also, could you add this printk() line to just before your err_mask hack:
>
>   printk("id[2]=0x%04x\n", id[2]);
>
>If we see 0x738c reported from that, then we *know* we should just continue
>rather than err'ing out as is presently done.
>
>Thanks

Re: Spinup command fails on WD3200JS

[Mark Lord]

Ryan Power wrote:
> Here's the section with the modifications you requested:
..
> The same section with "if (err_mask && id[2] != 0x738c)" in place of the 
> previous modification:
> [    2.216000] scsi0 : sata_sil
> [    2.216000] scsi1 : sata_sil
> [    2.216000] ata1: SATA max UDMA/100 cmd 0xf880c080 ctl 0xf880c08a 
> bmdma 0xf880c000 irq 16
> [    2.216000] ata2: SATA max UDMA/100 cmd 0xf880c0c0 ctl 0xf880c0ca 
> bmdma 0xf880c008 irq 16
> [    2.684000] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
> [    2.692000] ata1.00: ATA-7: Maxtor 6L320S0, BACE1G20, max UDMA/133
> [    2.692000] ata1.00: 625142448 sectors, multi 16: LBA48 NCQ (depth 0/32)
> [    2.708000] ata1.00: configured for UDMA/100
> [    3.176000] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
> [   10.944000] id[2]=0x37c8

Okay, above we can see the drive requires a spin-up command,
which now gets issued, and then we loop to retry the IDENTIFY.

> [   10.964000] ata2.00: ATA-7: WDC WD3200JS-57PDB0, 21.00M21, max UDMA/133
> [   10.964000] ata2.00: 625142448 sectors, multi 0: LBA48 NCQ (depth 0/1)
> [   10.972000] id[2]=0x738c
> [   10.972000] ata2.00: configured for UDMA/100

There we can see that, after the spin-up command, the IDENTIFY succeeds,
and the new signature value of 0x728c indicates that full IDENTIFY data
is now present.  So we can just continue at that point.

Good!

Now.. time to get your name in lights and all that!
Would you like to package up that new if-stmt (below)
as a nice and proper kernel patch?  Just follow the advice
in the SubmittingPatches file, or model things after other
patches you've seen here, and post the result with a
proper Signed-Off-By line, and I'll ack it.

		if (err_mask && id[2] != 0x738c)

Or leave it to me, and I'll steal your fame and fortune!  :)

Cheers
Thanks Ryan!

[PATCH 2.6.22.1] libata: Adjust libata to ignore errors after spinup

[Ryan Power]

From: Ryan Power <rpower@sysreset.com>

Adjust libata to ignore errors after spinup

This patch is to ignore errors from the spinup attempt if the drive is
in the "standby id" state.

Signed-off-by: Ryan Power <rpower@sysreset.com>

---

Index: drivers.new/ata/libata-core.c
--- drivers/ata/libata-core.c   2007-07-10 12:56:30.000000000 -0600
+++ drivers.new/ata/libata-core.c       2007-07-15 01:58:49.000000000 -0600
@@ -1750,7 +1750,7 @@ int ata_dev_read_id(struct ata_device *d
                 tf.protocol = ATA_PROT_NODATA;
                 tf.flags |= ATA_TFLAG_ISADDR | ATA_TFLAG_DEVICE;
                 err_mask = ata_exec_internal(dev, &tf, NULL, DMA_NONE, 
NULL, 0);
-               if (err_mask) {
+               if (err_mask && id[2] != 0x738c) {
                         rc = -EIO;
                         reason = "SPINUP failed";
                         goto err_out;

Re: [PATCH 2.6.22.1] libata: Adjust libata to ignore errors after spinup

[Mark Lord]

Ryan Power wrote:
> From: Ryan Power <rpower@sysreset.com>
> 
> Adjust libata to ignore errors after spinup
> 
> This patch is to ignore errors from the spinup attempt if the drive is
> in the "standby id" state.

Jeff / Tejun:  here is Ryan's patch for his WD drive spinup problems.
This copy has the pathnames and whitespace repaired.
 
Signed-off-by: Ryan Power <rpower@sysreset.com>
Signed-off-by: Mark Lord <mlord@pobox.com>
---
Index: linux/drivers/ata/libata-core.c
--- old/drivers/ata/libata-core.c   2007-07-10 12:56:30.000000000 -0600
+++ linux/drivers/ata/libata-core.c       2007-07-15 01:58:49.000000000 -0600
@@ -1750,7 +1750,7 @@ int ata_dev_read_id(struct ata_device *d
		tf.protocol = ATA_PROT_NODATA;
		tf.flags |= ATA_TFLAG_ISADDR | ATA_TFLAG_DEVICE;
		err_mask = ata_exec_internal(dev, &tf, NULL, DMA_NONE, NULL, 0);
-		if (err_mask) {
+		if (err_mask && id[2] != 0x738c) {
			rc = -EIO;
			reason = "SPINUP failed";
			goto err_out;

Re: [PATCH 2.6.22.1] libata: Adjust libata to ignore errors after spinup

[Mark Lord]

Mark Lord wrote:
> Ryan Power wrote:
>> From: Ryan Power <rpower@sysreset.com>
>>
>> Adjust libata to ignore errors after spinup
>>
>> This patch is to ignore errors from the spinup attempt if the drive is
>> in the "standby id" state.
> 
> Jeff / Tejun:  here is Ryan's patch for his WD drive spinup problems.
> This copy has the pathnames and whitespace repaired.

Mmm.. something weird happened there.
Here it is again, with corrected whitespace.

Signed-off-by: Ryan Power <rpower@sysreset.com>
Signed-off-by: Mark Lord <mlord@pobox.com>
---
Index: linux/drivers/ata/libata-core.c
--- old/drivers/ata/libata-core.c   2007-07-10 12:56:30.000000000 -0600
+++ linux/drivers/ata/libata-core.c       2007-07-15 01:58:49.000000000 -0600
@@ -1750,7 +1750,7 @@ int ata_dev_read_id(struct ata_device *d
		tf.protocol = ATA_PROT_NODATA;
		tf.flags |= ATA_TFLAG_ISADDR | ATA_TFLAG_DEVICE;
		err_mask = ata_exec_internal(dev, &tf, NULL, DMA_NONE, NULL, 0);
-		if (err_mask) {
+		if (err_mask && id[2] != 0x738c) {
			rc = -EIO;
			reason = "SPINUP failed";
			goto err_out;

Re: [PATCH 2.6.22.1] libata: Adjust libata to ignore errors after spinup

[Mark Lord]

Mark Lord wrote:
> Ryan Power wrote:
>> From: Ryan Power <rpower@sysreset.com>
>>
>> Adjust libata to ignore errors after spinup
>>
>> This patch is to ignore errors from the spinup attempt if the drive is
>> in the "standby id" state.
> 
> Jeff / Tejun:  here is Ryan's patch for his WD drive spinup problems.
> This copy has the pathnames and whitespace repaired.

Mmm.. Thunderbird-2.x seems to no longer keep my whitespace intact,
even when using the external editor plugin.. 

Hopefully this one (posted with thunderbird-1.5 + exteditor.xpi) works:

Signed-off-by: Ryan Power <rpower@sysreset.com>
Signed-off-by: Mark Lord <mlord@pobox.com>
---
Index: linux/drivers/ata/libata-core.c
--- old/drivers/ata/libata-core.c   2007-07-10 12:56:30.000000000 -0600
+++ linux/drivers/ata/libata-core.c       2007-07-15 01:58:49.000000000 -0600
@@ -1750,7 +1750,7 @@ int ata_dev_read_id(struct ata_device *d
		tf.protocol = ATA_PROT_NODATA;
		tf.flags |= ATA_TFLAG_ISADDR | ATA_TFLAG_DEVICE;
		err_mask = ata_exec_internal(dev, &tf, NULL, DMA_NONE, NULL, 0);
-		if (err_mask) {
+		if (err_mask && id[2] != 0x738c) {
			rc = -EIO;
			reason = "SPINUP failed";
			goto err_out;