Re: ata_special_intr, ide_do_drive_cmd deadlock

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Thunder from the hill]

Hi,

On Sun, 7 Jul 2002, Zwane Mwaikambo wrote:
> The trace is quite nice on this one.
> 
> [trace followed immediately]

Have you tried IDE 96+97 yet? They changed ata_special_intr and 
ide_do_drive_cmd heavily.

							Regards,
							Thunder
-- 
(Use http://www.ebb.org/ungeek if you can't decode)
------BEGIN GEEK CODE BLOCK------
Version: 3.12
GCS/E/G/S/AT d- s++:-- a? C++$ ULAVHI++++$ P++$ L++++(+++++)$ E W-$
N--- o?  K? w-- O- M V$ PS+ PE- Y- PGP+ t+ 5+ X+ R- !tv b++ DI? !D G
e++++ h* r--- y- 
------END GEEK CODE BLOCK------

ata_special_intr, ide_do_drive_cmd deadlock

[Zwane Mwaikambo]

The trace is quite nice on this one.

CPU:    0
EIP:    0010:[<c024d7f3>]    Not tainted
EFLAGS: 00000086
eax: c0455d9c   ebx: c15d2d34   ecx: 00000000   edx: cdfcdd24
esi: c0455ee4   edi: c0455ed0   ebp: c0455ee4   esp: cdfcdcbc
ds: 0018   es: 0018   ss: 0018
Process dd (pid: 668, threadinfo=cdfcc000 task=cee0ed00)
Stack: 00000046 00000000 00000001 dead4ead cdfcdcec cdfcdcec ff5aff5a ff5aff5a 
       ff5aff5a 00000000 00000001 dead4ead cdfcdcec cdfcdcec ff5aff5a ff5aff5a
       ff5aff5a c0455ed0 c0455ed0 cdfcdd8c 00000088 c024d7ed c0455ed0 cdfcdd24
Call Trace: [<c024d7ed>] [<c011cefe>] [<c024f641>] [<c024d590>] [<c024cef3>]
   [<c024d021>] [<c024f8ba>] [<c024fd47>] [<c024fe13>] [<c0230d89>] [<c023113d>] 
   [<c0146ae1>] [<c0146bf8>] [<c0134a5f>] [<c0134f80>] [<c013507c>] [<c0134f80>] 
   [<c014999c>] [<c0107efa>] [<c0149bea>] [<c01075ab>] 

Code: 80 3b 00 f3 90 7e f9 e9 c1 fc ff ff 80 3b 00 f3 90 7e f9 e9 

>>EIP; c024d7f3 <.text.lock.ide_taskfile+0/1d>   <=====
Trace; c024d7ed <ide_raw_taskfile+4d/53>
Trace; c011cefe <printk+1ae/210>
Trace; c024f641 <do_recalibrate+51/70>
Trace; c024d590 <ata_special_intr+0/210>
Trace; c024cef3 <ata_busy_poll+23/70>
Trace; c024d021 <ata_status_poll+a1/c0>
Trace; c024f8ba <start_request+ca/220>
Trace; c024fd47 <queue_commands+e7/170>
Trace; c024fe13 <do_request+43/70>
Trace; c0230d89 <generic_unplug_device+119/170>
Trace; c023113d <blk_run_queues+13d/150>
Trace; c0146ae1 <do_page_cache_readahead+161/180>
Trace; c0146bf8 <page_cache_readahead+f8/100>
Trace; c0134a5f <do_generic_file_read+7f/3c0>
Trace; c0134f80 <file_read_actor+0/80>
Trace; c013507c <generic_file_read+7c/130>
Trace; c0134f80 <file_read_actor+0/80>
Trace; c014999c <vfs_read+9c/160>
Trace; c0107efa <common_interrupt+22/28>
Trace; c0149bea <sys_read+2a/40>
Trace; c01075ab <syscall_call+7/b>
Code;  c024d7f3 <.text.lock.ide_taskfile+0/1d>
00000000 <_EIP>:
Code;  c024d7f3 <.text.lock.ide_taskfile+0/1d>   <=====
   0:   80 3b 00                  cmpb   $0x0,(%ebx)   <=====
Code;  c024d7f6 <.text.lock.ide_taskfile+3/1d>
   3:   f3 90                     repz nop
Code;  c024d7f8 <.text.lock.ide_taskfile+5/1d>
   5:   7e f9                     jle    0 <_EIP>
Code;  c024d7fa <.text.lock.ide_taskfile+7/1d>
   7:   e9 c1 fc ff ff            jmp    fffffccd <_EIP+0xfffffccd> c024d4c0 <ide_do_drive_cmd+e0/1b0>
Code;  c024d7ff <.text.lock.ide_taskfile+c/1d>
   c:   80 3b 00                  cmpb   $0x0,(%ebx)
Code;  c024d802 <.text.lock.ide_taskfile+f/1d>
   f:   f3 90                     repz nop
Code;  c024d804 <.text.lock.ide_taskfile+11/1d>
  11:   7e f9                     jle    c <_EIP+0xc> c024d7ff
<.text.lock.ide_taskfile+c/1d>
Code;  c024d806 <.text.lock.ide_taskfile+13/1d>
  13:   e9 00 00 00 00            jmp    18 <_EIP+0x18> c024d80b
<.text.lock.ide_taskfile+18/1d>

--
function.linuxpower.ca

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Zwane Mwaikambo]

On Sun, 7 Jul 2002, Thunder from the hill wrote:

> Have you tried IDE 96+97 yet? They changed ata_special_intr and 
> ide_do_drive_cmd heavily.

Thank you sir, i'll have a look.

Cheers,
	Zwane Mwaikambo

-- 
function.linuxpower.ca

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Bartlomiej Zolnierkiewicz]

If it was IDE 95, or IDE 95 on atapi device it is known, noted in 95's
changelog and fixed in 96...

--
Bartlomiej

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Zwane Mwaikambo]

On Sun, 7 Jul 2002, Bartlomiej Zolnierkiewicz wrote:

> 
> If it was IDE 95, or IDE 95 on atapi device it is known, noted in 95's
> changelog and fixed in 96...

On ATA disk, with 2.5.25 stock and the deadlock is still there (visual 
inspection) in IDE 97

Cheers,
	Zwane Mwaikambo
-- 
function.linuxpower.ca

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Zwane Mwaikambo]

On Sun, 7 Jul 2002, Zwane Mwaikambo wrote:

> > If it was IDE 95, or IDE 95 on atapi device it is known, noted in 95's
> > changelog and fixed in 96...
> 
> On ATA disk, with 2.5.25 stock and the deadlock is still there (visual 
> inspection) in IDE 97

Sorry perhaps let me elaborate, i was doing a dd if=/dev/hdX of=file then 
the drive dropped down to PIO, thats when i reckon i hit do_recalibrate. 
This was on 2.5.25.

Thanks,
	Zwane Mwaikambo

-- 
function.linuxpower.ca

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Bartlomiej Zolnierkiewicz]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 909 bytes --]


On Sun, 7 Jul 2002, Zwane Mwaikambo wrote:

> On Sun, 7 Jul 2002, Zwane Mwaikambo wrote:
>
> > > If it was IDE 95, or IDE 95 on atapi device it is known, noted in 95's
> > > changelog and fixed in 96...
> >
> > On ATA disk, with 2.5.25 stock and the deadlock is still there (visual
> > inspection) in IDE 97
>
> Sorry perhaps let me elaborate, i was doing a dd if=/dev/hdX of=file then
> the drive dropped down to PIO, thats when i reckon i hit do_recalibrate.
> This was on 2.5.25.

do_recalibrate is called under lock and it tries to acquire lock, so
deadlock, you was the first to notice it and you have even added FIXME
to the code... ;-)

Do you realise that 2.5.25 have IDE 93 and it should be fixed in IDE 96.

BTW: know problem with 96 is broken ide_timer_expiry().
Attached IDE 98 (or not) prepatch should fix it.

--
Bartlomiej

>
> Thanks,
> 	Zwane Mwaikambo
>
> --
> function.linuxpower.ca
>
>
>

[-- Attachment #2: Type: TEXT/PLAIN, Size: 6432 bytes --]

diff -ur -X/home/dontdiff linux-2.5.24/drivers/ide/alim15x3.c linux/drivers/ide/alim15x3.c
--- linux-2.5.24/drivers/ide/alim15x3.c	Tue Jul  2 23:54:16 2002
+++ linux/drivers/ide/alim15x3.c	Thu Jul  4 19:53:06 2002
@@ -362,8 +362,10 @@
 
 static void __init ali15x3_init_dma(struct ata_channel *ch, unsigned long dmabase)
 {
-	if ((dmabase) && (m5229_revision < 0x20))
+	if (dmabase && (m5229_revision < 0x20)) {
+		ch->autodma = 0;
 		return;
+	}
 
 	ata_init_dma(ch, dmabase);
 }
diff -ur -X/home/dontdiff linux-2.5.24/drivers/ide/ide-pci.c linux/drivers/ide/ide-pci.c
--- linux-2.5.24/drivers/ide/ide-pci.c	Tue Jul  2 23:54:16 2002
+++ linux/drivers/ide/ide-pci.c	Fri Jul  5 00:47:28 2002
@@ -313,13 +313,14 @@
 	 * already enabled by the primary channel run.
 	 */
 	pci_set_master(dev);
+
+	if (autodma)
+		ch->autodma = 1;
+
 	if (d->init_dma)
 		d->init_dma(ch, dma_base);
 	else
 		ata_init_dma(ch, dma_base);
-
-	if (ch->dma_base && autodma)
-		ch->autodma = 1;
 #endif
 
 no_dma:
diff -ur -X/home/dontdiff linux-2.5.24/drivers/ide/ide-taskfile.c linux/drivers/ide/ide-taskfile.c
--- linux-2.5.24/drivers/ide/ide-taskfile.c	Tue Jul  2 17:35:47 2002
+++ linux/drivers/ide/ide-taskfile.c	Fri Jul  5 01:30:41 2002
@@ -220,7 +220,7 @@
 	else if (!blk_queue_empty(&drive->queue))
 		queue_head = queue_head->prev;	/* ide_end and ide_wait */
 
-	q->elevator.elevator_add_req_fn(q, rq, queue_head);
+	__elv_add_request(q, rq, queue_head);
 
 	do_ide_request(q);
 
diff -ur -X/home/dontdiff linux-2.5.24/drivers/ide/ide.c linux/drivers/ide/ide.c
--- linux-2.5.24/drivers/ide/ide.c	Tue Jul  2 17:36:23 2002
+++ linux/drivers/ide/ide.c	Fri Jul  5 01:21:30 2002
@@ -277,6 +277,7 @@
 			ata_set_handler(drive, reset_pollfunc, HZ/20, NULL);
 			ret = ide_started;	/* continue polling */
 		} else {
+			ch->poll_timeout = 0;	/* done polling */
 			printk("%s: reset timed out, status=0x%02x\n", ch->name, drive->status);
 			++drive->failures;
 			ret = ide_stopped;
@@ -284,6 +285,7 @@
 	} else  {
 		u8 stat;
 
+		ch->poll_timeout = 0;	/* done polling */
 		printk("%s: reset: ", ch->name);
 		if ((stat = GET_ERR()) == 1) {
 			printk("success\n");
@@ -314,7 +316,6 @@
 
 		ret = ide_stopped;
 	}
-	ch->poll_timeout = 0;	/* done polling */
 
 	return ret;
 }
@@ -337,25 +338,17 @@
 static ide_startstop_t do_reset1(struct ata_device *drive, int try_atapi)
 {
 	unsigned int unit;
-	unsigned long flags;
 	struct ata_channel *ch = drive->channel;
 
-	/* FIXME:  --bzolnier */
-	__save_flags(flags);	/* local CPU only */
-	__cli();		/* local CPU only */
-
 	/* For an ATAPI device, first try an ATAPI SRST. */
-	if (try_atapi) {
-		if (drive->type != ATA_DISK) {
-			check_crc_errors(drive);
-			ata_select(drive, 20);
-			OUT_BYTE(WIN_SRST, IDE_COMMAND_REG);
-			ch->poll_timeout = jiffies + WAIT_WORSTCASE;
-			ata_set_handler(drive, atapi_reset_pollfunc, HZ/20, NULL);
-			__restore_flags(flags);	/* local CPU only */
+	if (try_atapi && drive->type != ATA_DISK) {
+		check_crc_errors(drive);
+		ata_select(drive, 20);
+		OUT_BYTE(WIN_SRST, IDE_COMMAND_REG);
+		ch->poll_timeout = jiffies + WAIT_WORSTCASE;
+		ata_set_handler(drive, atapi_reset_pollfunc, HZ/20, NULL);
 
-			return ide_started;
-		}
+		return ide_started;
 	}
 
 	/*
@@ -365,8 +358,7 @@
 	for (unit = 0; unit < MAX_DRIVES; ++unit)
 		check_crc_errors(&ch->drives[unit]);
 
-	__restore_flags(flags);	/* local CPU only */
-
+	/* FIXME: and then we should reset it  --bzolnier */
 	return ide_started;
 }
 
@@ -547,6 +539,8 @@
 	u8 stat = drive->status;
 
 	err = ata_dump(drive, rq, msg);
+
+	/* FIXME: at least !drive check is bogus  --bzolnier */
 	if (!drive || !rq)
 		return ide_stopped;
 
@@ -703,7 +697,7 @@
 		/* This device is sleeping and waiting to be serviced
 		 * later than any other device we checked thus far.
 		 */
-		if (drive->sleep && (!sleep || time_after(sleep, drive->sleep)))
+		if (drive->sleep && (!sleep || time_after(drive->sleep, sleep)))
 			sleep = drive->sleep;
 	}
 
@@ -729,7 +723,7 @@
 
 		/* There are no request pending for this device.
 		 */
-		if (list_empty(&drive->queue.queue_head))
+		if (blk_queue_empty(&drive->queue))
 			continue;
 
 		/* This device still wants to remain idle.
@@ -916,7 +910,7 @@
 	del_timer(&ch->timer);
 
 	if (!ch->drive) {
-		printk(KERN_ERR "%s: IRQ handler was NULL\n", __FUNCTION__);
+		printk(KERN_ERR "%s: channel->drive was NULL\n", __FUNCTION__);
 		ch->handler = NULL;
 	} else if (!ch->handler) {
 
@@ -936,7 +930,7 @@
 
 		/* paranoia */
 		if (!test_and_set_bit(IDE_BUSY, ch->active))
-			printk(KERN_ERR "%s: %s: IRQ handler was not busy?!\n",
+			printk(KERN_ERR "%s: %s: channel was not busy?!\n",
 					drive->name, __FUNCTION__);
 
 		if (ch->expiry) {
@@ -966,12 +960,13 @@
 		handler = ch->handler;
 		ch->handler = NULL;
 
-		ch = drive->channel;
+		spin_unlock(ch->lock);
 #if DISABLE_IRQ_NOSYNC
 		disable_irq_nosync(ch->irq);
 #else
 		disable_irq(ch->irq);	/* disable_irq_nosync ?? */
 #endif
+		/* FIXME: IRQs are already disabled by spin_lock_irqsave()  --bzolnier */
 		__cli();	/* local CPU only, as if we were handling an interrupt */
 		if (ch->poll_timeout) {
 			ret = handler(drive, drive->rq);
@@ -1020,6 +1015,7 @@
 			ret = ata_error(drive, drive->rq, "irq timeout");
 
 		enable_irq(ch->irq);
+		spin_lock_irq(ch->lock);
 
 		if (ret == ide_stopped)
 			clear_bit(IDE_BUSY, ch->active);
diff -ur -X/home/dontdiff linux-2.5.24/drivers/ide/pdc202xx.c linux/drivers/ide/pdc202xx.c
--- linux-2.5.24/drivers/ide/pdc202xx.c	Tue Jul  2 23:54:16 2002
+++ linux/drivers/ide/pdc202xx.c	Fri Jul  5 00:51:02 2002
@@ -165,9 +165,6 @@
 	u8 DP;
 #endif
 
-	if (drive->dn > 3) /* FIXME: remove this --bkz */
-		return -1;
-
 	drive_pci = 0x60 + (drive->dn << 2);
 
 	if ((drive->type != ATA_DISK) && (speed < XFER_SW_DMA_0))
diff -ur -X/home/dontdiff linux-2.5.24/drivers/ide/sis5513.c linux/drivers/ide/sis5513.c
--- linux-2.5.24/drivers/ide/sis5513.c	Tue Jul  2 23:54:16 2002
+++ linux/drivers/ide/sis5513.c	Fri Jul  5 00:50:30 2002
@@ -273,9 +273,6 @@
 	       drive->dn, pio, timing);
 #endif
 
-	if (drive->dn > 3)	/* FIXME: remove this  --bkz */
-		return 1;
-
 	drive_pci = 0x40 + (drive->dn << 1);
 
 	/* register layout changed with newer ATA100 chips */

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Bartlomiej Zolnierkiewicz]

While at it, please don't spent too much time on locking.
I reverted it to what 2.4.x (early 2.5?) kernels do and it should
work fine, remeber IDE_BUSY bit protects us from reentering
ide_do_request() (while it is set nothing will pass down this function
and REQ_STARTED request's flag protects from block layer.

Locking will be slightly changed/fixed but not now, but after fixing many
much more urgent issues...
I simply dont want to waste time on fixing locking n times.

Regards
--
Bartlomiej

Re: ata_special_intr, ide_do_drive_cmd deadlock

[Zwane Mwaikambo]

On Sun, 7 Jul 2002, Bartlomiej Zolnierkiewicz wrote:

> do_recalibrate is called under lock and it tries to acquire lock, so
> deadlock, you was the first to notice it and you have even added FIXME
> to the code... ;-)

I thought you had backed out most if not all those locking changes.

> Do you realise that 2.5.25 have IDE 93 and it should be fixed in IDE 96.

That i wasn't aware of, thanks i'm currently looking at 97

> BTW: know problem with 96 is broken ide_timer_expiry().
> Attached IDE 98 (or not) prepatch should fix it.

Thanks,
	Zwane Mwaikambo

-- 
function.linuxpower.ca

IDE94 lockup on lock_page or __wait_on_buffer

[Petr Vandrovec]

On Sun, Jul 07, 2002 at 07:27:18PM +0200, Bartlomiej Zolnierkiewicz wrote:
> 
> Do you realise that 2.5.25 have IDE 93 and it should be fixed in IDE 96.
> 
> BTW: know problem with 96 is broken ide_timer_expiry().
> Attached IDE 98 (or not) prepatch should fix it.

Hello,
  there is something wrong with IDE94 :-( I'm starring at this problem for
6 hours, but I still cannot explain that. After applying IDE94 and
simple booting with:

Linux init=/bin/bash
# bash < /dev/tty2 > /dev/tty2 2>&1 &
<change to vt2>
# dd if=/dev/hdg of=/dev/null bs=4k
<change back to vt1>
# df

system deadlocks. Call stack is either (when dd locks)

__lock_page
lock_page
filemap_nopage  (first call to lock_page, at line 1550)
do_no_page
handle_mm_fault
do_page_fault
error_code

or (when bash dies while trying to start df)

__wait_on_buffer
__bread_slow
__getblk
ext2_get_inode
ext2_read_inode
ext2_lookup
real_lookup
do_lookup
link_path_walk
path_lookup
__user_walk
vfs_stat
sys_stat64
syscall_call

Probably IDE messes its request queue and forgets to execute some requests,
or what's going on...

None of running processes (2x bash, dd, keventd, 
ksoftirqd...) is executing IDE code when the deadlock happens. IDE channel
in question is dead after deadlock occurs (hdparm -d 0 /dev/hde says 
channel busy after some timeout).

Kernel is up, non-preemptible, running on 1GHz Athlon, 
one UDMA100 IDE (hde) and one UDMA33 IDE (hdg) connected to pdc20265, 512MB 
RAM. I did not notice any problem while using this patch for last 7 days 
on 450MHz PIII, two UDMA33 IDE connected to PIIX4, 640MB RAM.

Problem occurs even with latest ide-98-pre.
					Thanks,
						Petr Vandrovec
						vandrove@vc.cvut.cz