by Alan Chandler

[permalink] [raw]

Subject: Re: ide-cd problem

On Tuesday 23 November 2004 21:49, Alan Chandler wrote:
> On Tuesday 23 November 2004 14:51, Jens Axboe wrote:
> > On Tue, Nov 23 2004, Alan Chandler wrote:
> > > On Monday 22 November 2004 23:48, Alan Chandler wrote:
> > > ...
> > >
> > > > If I make the delay 600ns it works - I guess my hardware is a little
> > > > off spec.
...
> There is good and bad news related to 2.6.10-rc2
>
> The good news is that the acpi problem was the cause of the startup issues.
> adding pci=noacpi to the boot command line fixed that.
>
> The bad news is that with the delay at 800ns in drive_is_ready() I am
> getting the exact same symptoms I got with 2.6.9 before upping the delay to
> over 540ns.
...
>
> Firstly, the symptoms are the same between 2.6.9 and 2.6.10-rc2. The halt
> seem to always be in exactly the same place. If it was a timing problem I
> would have thought it would have varied.
>
> Secondly, the command before seems to have an expectation of a 2048
> transfer rather than the 0 in the command, before the problem and then you
> get the strange DRQ=1 but 0 in the len register.
>
> Nov 23 20:37:33 kanger kernel: ide-cd:ide_do_rq_cdrom - cmd = 0x0
> Nov 23 20:37:33 kanger kernel: ide-cd:cdrom_newpc_intr - cmd=0x0 stat=0x50
> ireason=3 len=2048 rq len=0
> Nov 23 20:37:33 kanger kernel: ide-cd:ide_do_rq_cdrom - cmd = 0x1b
> Nov 23 20:37:33 kanger kernel: ide-cd:cdrom_newpc_intr - cmd=0x1b stat=0x58
> ireason=2 len=0 rq len=0
>

I have looked at this "every which way" to try and understand what is
happening, and now think I have a handle on it.

The Test Unit Ready command (cmd=0x00) is the first command in the sequence
that is issued with an expectation of no data being returned (rq len=0), but
for some reason (which I don't know why) the device has decided it has data
to send us (len=2048). I was confused for a long time because in normal
circumstances cdrom_newpc_intr() is entered twice for a packet command with a
data transfer attached, the first time with DRQ asserted and rq len == len,
and once the transfer has taken place with DRQ not asserted and rq len having
been set to 0 whilst len remains at its original value. But in the case
shown above, the first time cdrom_newpc_intr() is entered rq len (actually
rq->data_len) is set to zero

In this case and (as far as I can see related to the packet commands) only
this case, with my drive (CW078D), there is a delay between IRQ being
asserted to say the command has been completed and DRQ being raised. (DRQ for
the other cases seems to be asserted by the time of the interrupt).

Once DRQ is asserted in this way, and until some command tries to read the
data it wants to send us, it remains asserted. That is why the start stop
unit command (0x1b) appears to be the one that is failing. In one trial I
conducted I made this command into a no op - returning successfully, and the
problem just full into the next command in sequence.

I was also experiencing different symptoms between 2.6.9 and 2.6.10-rc2, in
that a change made to solve the problem in 2.6.9 (changing the delay in
drive_is_ready to 600ns) did not appear to work in 2.6.10-rc2. I haven't
quite got to the bottom of this - but as the patch below shows, I have
plugged what might be race conditions similar to the one identified by Alan
Cox. I do not fully understand the logic of the Alan's race condition, as
from comments elsewhere in the code (and I really don't know how it really
works) it says linux does not allow rentrant interrupts on the same unit - so
I don't understand why the spinlocks need to be there, so my logic maybe
totally spurious in this case - except it did make the difference between it
working in 2.6.9 and getting it to work in 2.6.10-rc2.

I did attempt in early tests I did with 2.6.9 to determine the accurately the
size of the delay needed, it appeared to be around 540ns (400ns was not
enough). I have done all recent tests with 2.6.10-rc2 and 400ns is not
enough 600ns is. I have searched all over the ATAPI spec, but I can not see
any really definitive statement on DRQ assertion in this case. There is of
course the 400ns delay in removing IRQ after either reading the status
register or writing to the command register (clause 5.2.9), which the code
seems to interpret as 400ns after either occurrence, but which my reading of
the spec would be 400ns after the first occurence of one of these. As I
indicated in a previous note on this, as we always read the status register
at the start of interrupt processing (in drive_is_ready), perhaps the
solution is to store jiffies at this point and then delay 400ns - difference
between jiffies now and as we exit ide_intr().

The other place where any delay is mentioned is when transitioning from bus
idle state to various command state following issue of a command. Again the
400ns is mentioned. In the specific case of the packet command, this delay
seems to need to be when the packet command is written - and before the
command packet is transfered. The only delay mentioned after that point is
the one pio cycle (where it recommends reading the alt status reg) before
checking status. Given that we read the status twice (drive_is_ready and
cdrom_decode_status) it appears we fufil this rule.

In fact, unless someone can point me at another place in the spec, the
implication is that DRQ will be correct at the time of the interrupt and two
reads of the status register that we do when entering cdrom_newpc_intr. So I
Have to conclude that my CD is operating outside of spec in this case.

This patch below is not a definitive answer to the issue, rather an
illustration of the test envionment I was using to show things working. You
will see from the patches in drivers/ide/ide-iops.c that I have removed most
of the timing delays, mainly to get a real handle on what was needed in
ide-cd.c. I never had any problem with delays apart from the one described
above

Index: drivers/ide/ide-iops.c
===================================================================
--- drivers/ide/ide-iops.c (.../vendor/2.6.10-rc2) (revision 14)
+++ drivers/ide/ide-iops.c (.../akc/delay) (revision 14)
@@ -476,10 +476,6 @@
if (drive->waiting_for_dma)
return hwif->ide_dma_test_irq(drive);

-#if 0
- /* need to guarantee 400ns since last command was issued */
- udelay(1);
-#endif

#ifdef CONFIG_IDEPCI_SHARE_IRQ
/*
@@ -560,7 +556,6 @@
return 1;
}

- udelay(1); /* spec allows drive 400ns to assert "BUSY" */
if ((stat = hwif->INB(IDE_STATUS_REG)) & BUSY_STAT) {
local_irq_set(flags);
timeout += jiffies;
@@ -589,11 +584,13 @@
* rather than expensively fail things immediately.
* This fix courtesy of Matthew Faupel & Niccolo Rigacci.
*/
- for (i = 0; i < 10; i++) {
- udelay(1);
+
+ /* take out this fix temporarily to test out what is happening without
distractions*/
+/* for (i = 0; i < 10; i++) {
+ udelay(1);*/
if (OK_STAT((stat = hwif->INB(IDE_STATUS_REG)), good, bad))
return 0;
- }
+/* }*/
*startstop = DRIVER(drive)->error(drive, "status error", stat);
return 1;
}
Index: drivers/ide/ide-cd.c
===================================================================
--- drivers/ide/ide-cd.c (.../vendor/2.6.10-rc2) (revision 14)
+++ drivers/ide/ide-cd.c (.../akc/delay) (revision 14)
@@ -890,8 +890,13 @@
ide_execute_command(drive, WIN_PACKETCMD, handler, ATAPI_WAIT_PC,
cdrom_timer_expiry);
return ide_started;
} else {
- /* packet command */
- HWIF(drive)->OUTB(WIN_PACKETCMD, IDE_COMMAND_REG);
+ unsigned long flags;
+
+ /* packet command */
+ spin_lock_irqsave(&ide_lock, flags);
+ HWIF(drive)->OUTBSYNC(drive, WIN_PACKETCMD, IDE_COMMAND_REG);
+ ndelay(400);
+ spin_unlock_irqrestore(&ide_lock, flags);
return (*handler) (drive);
}
}
@@ -938,8 +943,12 @@
cmd_len = ATAPI_MIN_CDB_BYTES;

/* Send the command to the device. */
+ unsigned long flags;
+ spin_lock_irqsave(&ide_lock, flags);
HWIF(drive)->atapi_output_bytes(drive, rq->cmd, cmd_len);
-
+ ndelay(400);
+ spin_unlock_irqrestore(&ide_lock, flags);
+
/* Start the DMA if need be */
if (info->dma)
hwif->dma_start(drive);
@@ -1649,6 +1658,8 @@
xfer_func_t *xferfunc;
unsigned long flags;

+ /* delay here enough to ensure the command has had time to complete and
decide if its going to set DRQ */
+ ndelay(600);
/* Check for errors. */
dma_error = 0;
dma = info->dma;
@@ -1665,7 +1676,6 @@
*/
if (dma) {
if (dma_error) {
- printk("ide-cd: dma error\n");
__ide_dma_off(drive);
return DRIVER(drive)->error(drive, "dma error", stat);
}
@@ -1737,10 +1747,19 @@
if (blen > thislen)
blen = thislen;

- xferfunc(drive, ptr, blen);
-
thislen -= blen;
len -= blen;
+
+ if((thislen <=0) && (len<=0)) {
+ unsigned long flags;
+ /* this is the last of this output */
+ spin_lock_irqsave(&ide_lock, flags);
+ xferfunc(drive, ptr, blen);
+ ndelay (400);
+ spin_unlock_irqrestore(&ide_lock, flags);
+ } else
+ xferfunc(drive,ptr,blen);
+
rq->data_len -= blen;

if (rq->bio)
@@ -1748,7 +1767,7 @@
else
rq->data += blen;
}
-
+
/*
* pad, if necessary
*/
@@ -1756,10 +1775,19 @@
while (len > 0) {
int pad = 0;

- xferfunc(drive, &pad, sizeof(pad));
len -= sizeof(pad);
+ if (len <= 0) {
+ unsigned long flags;
+
+ /* last output */
+ spin_lock_irqsave(&ide_lock,flags);
+ xferfunc(drive, &pad, sizeof(pad));
+ ndelay(400);
+ spin_unlock_irqrestore(&ide_lock,flags);
+ } else
+ xferfunc(drive, &pad, sizeof(pad));
}
- }
+ }

if (HWGROUP(drive)->handler != NULL)
BUG();

--
Alan Chandler
[email protected]
First they ignore you, then they laugh at you,
then they fight you, then you win. --Gandhi