SATA: Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052

SATA: Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052

[Soeren Sonnenburg]

Hi Jeff,

I am using your ata-passthru patch

http://www.kernel.org/pub/linux/kernel/people/jgarzik/libata/2.6.12-git4-passthru1.patch.bz2  


with hddtemp regularly polling for the temperature state together with
libsata from kernel 2.6.12 on a promise tx2. The disk is set to go to
sleep mode (hdparm -S 35 /dev/sda). And after a couple of hours the
machine oopsed (the disk was sleeping/not mounted at that time - with
high probability) :

ata2: command timeout
ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052
ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
ata2: status=0xb0 { Busy }
Unable to handle kernel NULL pointer dereference at virtual address 00000000
 printing eip:
c0118eac
*pde = 00000000
Oops: 0002 [#1]
CPU:    0
EIP:    0060:[<c0118eac>]    Tainted: P      VLI
EFLAGS: 00010082   (2.6.12) 
EIP is at complete+0xc/0x40
eax: 00000000   ebx: 00000082   ecx: 00000000   edx: 00000000
esi: f3b45ab8   edi: 00000292   ebp: f7d11e7c   esp: f7d11e64
ds: 007b   es: 007b   ss: 0068
Process scsi_eh_1 (pid: 320, threadinfo=f7d10000 task=f7c735b0)
Stack: 00000000 f3b45ab8 00000292 c0311544 f7c02c4c f7c71b40 f7c02c4c c03125d4 
       f3b45ab8 c02d18f2 f3b45ab8 f7c72460 c0350945 f3b45ab8 00000001 00000000 
       00000016 f7c7252e f5df5dc6 f7c72460 c0350c9e f7c72460 00000001 00000000 
Call Trace:
 [<c0311544>] blk_end_sync_rq+0x24/0x40
 [<c03125d4>] end_that_request_last+0x54/0xa0
 [<c02d18f2>] add_disk_randomness+0x32/0x40
 [<c0350945>] scsi_end_request+0xb5/0xe0
 [<c0350c9e>] scsi_io_completion+0x17e/0x4e0
 [<c035d650>] sd_rw_intr+0xc0/0x230
 [<c034be6e>] scsi_finish_command+0x8e/0xb0
 [<c035b1d5>] ata_scsi_qc_complete+0x45/0x90
 [<c0358d6a>] ata_qc_complete+0x3a/0xd0
 [<c035c480>] pdc_eng_timeout+0x90/0x120
 [<c035ad2a>] ata_scsi_error+0x1a/0x30
 [<c034fcea>] scsi_error_handler+0x8a/0xd0
 [<c034fc60>] scsi_error_handler+0x0/0xd0
 [<c0101311>] kernel_thread_helper+0x5/0x14
Code: eb fe ff ff 53 9d 8b 5d f4 8b 75 f8 8b 7d fc c9 c3 8d b4 26 00 00 00 00 8d bc 27 00 00 00 00 55 89 e5 83 ec 18 89 5d fc 9c 5b fa <ff> 00 83 c0 04 c7 44 24 10 00 00 00 00 c7 44 24 0c 00 00 00 00 

I am now trying w/o hddtemp, lets see how long it survives...

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

Re: SATA: Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052

[Soeren Sonnenburg]

On Thu, 2005-07-07 at 12:43 +0400, Alexey Dobriyan wrote:
> On Thursday 07 July 2005 12:04, Soeren Sonnenburg wrote:
> > with hddtemp regularly polling for the temperature state together with
> > libsata from kernel 2.6.12 on a promise tx2. The disk is set to go to
> > sleep mode (hdparm -S 35 /dev/sda). And after a couple of hours the
> > machine oopsed (the disk was sleeping/not mounted at that time - with
> > high probability) :
> > 
> > ata2: command timeout
> > ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> > Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052
> > ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> > ata2: status=0xb0 { Busy }
> > Unable to handle kernel NULL pointer dereference at virtual address 00000000
> 
> > EIP:    0060:[<c0118eac>]    Tainted: P      VLI
> 
> > I am now trying w/o hddtemp, lets see how long it survives...
> 
> With untainted kernel, please. To be sure it's our problem.

Sorry but I am. The machine never hung/oopsed before. The only new thing
now is the sata disk.

Soeren
-- 
"They that can give up essential liberty to obtain a little temporary
safety deserve neither liberty nor safety." Benjamin Franklin

Re: SATA: Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052

[Alexey Dobriyan]

On Thursday 07 July 2005 12:04, Soeren Sonnenburg wrote:
> with hddtemp regularly polling for the temperature state together with
> libsata from kernel 2.6.12 on a promise tx2. The disk is set to go to
> sleep mode (hdparm -S 35 /dev/sda). And after a couple of hours the
> machine oopsed (the disk was sleeping/not mounted at that time - with
> high probability) :
> 
> ata2: command timeout
> ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052
> ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> ata2: status=0xb0 { Busy }
> Unable to handle kernel NULL pointer dereference at virtual address 00000000

> EIP:    0060:[<c0118eac>]    Tainted: P      VLI

> I am now trying w/o hddtemp, lets see how long it survives...

With untainted kernel, please. To be sure it's our problem.

Re: SATA: Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052

[Soeren Sonnenburg]

On Thu, 2005-07-07 at 12:43 +0400, Alexey Dobriyan wrote:
> On Thursday 07 July 2005 12:04, Soeren Sonnenburg wrote:
> > with hddtemp regularly polling for the temperature state together with
> > libsata from kernel 2.6.12 on a promise tx2. The disk is set to go to
> > sleep mode (hdparm -S 35 /dev/sda). And after a couple of hours the
> > machine oopsed (the disk was sleeping/not mounted at that time - with
> > high probability) :
> > 
> > ata2: command timeout
> > ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> > Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052
> > ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> > ata2: status=0xb0 { Busy }
> > Unable to handle kernel NULL pointer dereference at virtual address 00000000
> 
> > EIP:    0060:[<c0118eac>]    Tainted: P      VLI
> 
> > I am now trying w/o hddtemp, lets see how long it survives...
> 
> With untainted kernel, please. To be sure it's our problem.

Ok, I've found a way to reproduce it without loading any prop. stuff.

1. boot with init=/bin/sh
2. run hdparm -S 1 /dev/sda
3. run hddtemp /dev/sda
4. immediate oops

another hang:

1. boot with init=/bin/sh
2. run hdparm -y /dev/sda

Nevertheless, as promised I rand without hddtemp for about a day. I got
this single error:

ata2: translated ATA stat/err 0x25/00 to SCSI SK/ASC/ASCQ 0x4/00/00
ata2: status=0x25 { DeviceFault CorrectedError Error }
SCSI error : <1 0 0 0> return code = 0x8000002
sda: Current: sense key: Hardware Error
    Additional sense: No additional sense information
end_request: I/O error, dev sda, sector 240910336

I will reverse apply the patch and proceed w/o hddtemp/hdparm... lets
see whether it survives this night.

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

Re: SATA: Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052

[Soeren Sonnenburg]

On Fri, 2005-07-08 at 09:46 +0200, Soeren Sonnenburg wrote:
> On Thu, 2005-07-07 at 12:43 +0400, Alexey Dobriyan wrote:
> > On Thursday 07 July 2005 12:04, Soeren Sonnenburg wrote:
> > > with hddtemp regularly polling for the temperature state together with
> > > libsata from kernel 2.6.12 on a promise tx2. The disk is set to go to
> > > sleep mode (hdparm -S 35 /dev/sda). And after a couple of hours the
> > > machine oopsed (the disk was sleeping/not mounted at that time - with
> > > high probability) :
> > > 
> > > ata2: command timeout
> > > ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> > > Assertion failed! qc->flags & ATA_QCFLAG_ACTIVE,drivers/scsi/libata-core.c,ata_qc_complete,line=3052
> > > ata2: translated ATA stat/err 0xb0/00 to SCSI SK/ASC/ASCQ 0xb/47/00
> > > ata2: status=0xb0 { Busy }
> > > Unable to handle kernel NULL pointer dereference at virtual address 00000000
> > 
> > > EIP:    0060:[<c0118eac>]    Tainted: P      VLI
> > 
> > > I am now trying w/o hddtemp, lets see how long it survives...
> > 
> > With untainted kernel, please. To be sure it's our problem.
> 
> Ok, I've found a way to reproduce it without loading any prop. stuff.
> 
> 1. boot with init=/bin/sh
> 2. run hdparm -S 1 /dev/sda
> 3. run hddtemp /dev/sda
> 4. immediate oops
> 
> another hang:
> 
> 1. boot with init=/bin/sh
> 2. run hdparm -y /dev/sda
> 
> Nevertheless, as promised I rand without hddtemp for about a day. I got
> this single error:
> 
> ata2: translated ATA stat/err 0x25/00 to SCSI SK/ASC/ASCQ 0x4/00/00
> ata2: status=0x25 { DeviceFault CorrectedError Error }
> SCSI error : <1 0 0 0> return code = 0x8000002
> sda: Current: sense key: Hardware Error
>     Additional sense: No additional sense information
> end_request: I/O error, dev sda, sector 240910336
> 
> I will reverse apply the patch and proceed w/o hddtemp/hdparm... lets
> see whether it survives this night.

Ok, so I now ran the machine over the weekend w/o the patch so no
hddtemp/hddparm (and no smartd also). None of the problems above
appeared, but instead 

ata2: status=0x51 { DriveReady SeekComplete Error }
ata2: error=0x0c { DriveStatusError }

occassionally (i.e. 9 times when transferring ~400 GB from/to the disk).

This is vanilla 2.6.12... Is this error problematic ? What is causing
this ?

Any ideas ?

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