Bug 6710

Created attachment 8334 [details]
Kernel syslog detailing CD reading error

The messages from the CD reading errors start on line 204, *not* line 850 as I
originally wrote in the bug description above.

Good news! The CD drive works if I turn off DMA with the following command
before mounting: 

hdparm -d0 /dev/hdc 


However, adding "hdc=nodma" in GRUB does not disable dma (this in itself could
be a bug...)  

The spec for this drive
(http://support.dell.com/support/edocs/storage/tormargi/Specs.htm) says that it
supports multiword DMA mode 2. I've checked that DMA is indeed on in Windows 98.
But when I tried turning on DMA mode 2 in Linux, the drive locked up as before: 

hdparm -d1 

Created attachment 8806 [details]
Libata errors from dmesg caused by probing the DVD-ROM drive

The dmesg for 2.6.18-rc4-mm that shows libata errors when trying to probe the
DVD-ROM drive. It's interesting that initially it says "ata2: PATA max
UDMA/33ata2: PATA max UDMA/33" even though the drive is only capable of
multiword DMA mode 2 and PIO mode 4 according to its specs (
http://support.dell.com/support/edocs/storage/tormargi/Specs.htm )

Nevertheless, libata seems to recognize the correct mode later on "ata2.00:
ATAPI, max MWDMA2, CDB intr".

Created attachment 8820 [details]
Libata errors when CD drive freezes while doing md5sum

If I add "TORiSAN DVD-ROM DRD-N216" to ata_dma_blacklist[] on line 2990 of
drivers/ata/libata-core.c, I am able to mount CDs. However, md5sum fails for
some files on the CD, and eventually the drive freezes with the following
message in dmesg. The CD is definitely good since md5sum works on my other
computer. If having ssh access to affected computer would help someone solve
this error, I'd be happy to arrange that.

Reassigning to the new ide-cd Maintainer.

Created attachment 10827 [details]
Libata trace with TORiSAN DRD-N216 configiured to MWDMA2

From the trace of Vlad, it seems the drive incorrectly sets DRQ after the DMA
is completed. That's why the ATAPI DMA (mwdma2) doesn't work for this drive.

Created attachment 10828 [details]
Libata trace with TORiSAN DRD-N216 configiured to PIO4

With the TORiSAN DRD-N216 DMA blacklisted, libata can configure and initialize
the drive to PIO4 properly. Mount cd also works. No more DRQ when the command
is completed as seen in mwdma2 mode.

The remaining problem is, after some reading from the CD, the device stopped
work suddenly. Reading the status register didn't clear INTRQ and the status
register was stuck to 0x58.

I am waiting for Vlad to submit the full dmesg with libata debugging traces.
Hopefully we can see what happened right before the device went wrong.

Created attachment 10830 [details]
Previous Libata trace with TORiSAN DRD-N216 configiured to PIO4 

This is the previous dmesg from Vlad with DRD-N216 configured to PIO4.
We can see some early irq before the hsm violation.

Created attachment 10831 [details]
Possible fix for the problem

I guess the TORiSAN DVD-ROM DRD-N216 drive might need the following quirk?
- All commands except read/write must be done in PIO
- Read/write commands must be done in DMA

Hi Vlad,

Could you please
- remove the "TORiSAN DRD-N216" from the DMA blacklist
- try the attached patch (together with previous debug patches).
  (Please make sure ata_check_atapi_dma() looks the same as in this patch.)

Thanks.

Created attachment 10833 [details]
Full dmesg showing which command causes the DVD drive to mess up

This is the same dmesg as in Comment #7, except that here it is complete and
unedited. It shows which command causes the DVD drive to mess up. Posted in
response to http://article.gmane.org/gmane.linux.ide/17327 .

I'm still compiling the patch from Comment #10, and I'll post its output soon.

Created attachment 10855 [details]
Please ignore -- I forgot to remove the "TORiSAN DRD-N216" from the DMA blacklist as indicated in Comment #10. I will make the correct change and try again now...

This is the full dmesg after applying the patch from Comment #10. The drive
still seems to freeze as before.

Thank you,
Vlad

Created attachment 10856 [details]
Dmesg after removing drive from DMA blacklist and applying patch from Comment #10

This is the dmesg after removing "TORiSAN DVD-ROM DRD-N216" from the DMA
blacklist and after applying the patch from comment #10. I made sure to keep
the previous debug patches and to check that ata_check_atapi_dma() looks the
same as in the patch from comment #10.

Thanks,
Vlad

It seems under DMA mode, the device somehow finished the DMA but didn't 
interrupt the adapter. (Maybe it did, but too early and ingored by the adapter.)
As shown below, we can see the host_stat changed from 0x1 (dma on going) to 0x0 
(dma completed); but the host adapter never see INTRQ.

====================
Mar 19 08:13:52 debian kernel: CDB (2:0,0,0) 28 00 00 00 eb 0e 00 00 40
Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 4
Mar 19 08:13:52 debian kernel: ata2: host_stat 0x4
Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 4 (dev_stat 0x58)
Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
Mar 19 08:13:52 debian kernel: ata2: host_stat 0x1
Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
Mar 19 08:13:52 debian kernel: ata2: host_stat 0x1
Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
Mar 19 08:13:52 debian kernel: ata2: host_stat 0x0
Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
Mar 19 08:13:52 debian kernel: ata2: host_stat 0x0
Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
...

Created attachment 10864 [details]
One more fix to workaround the 0x0 host_stat

Maybe we can safely assume it is "our interrupt" if the DMA active bit is
already cleared.

Hi Vlad,

Could you please apply this patch on top of previous patches and see if this
helps, thanks.

Created attachment 10865 [details]
Dmesg after applying patch from Comment #15

This is the dmesg after applying the patch from Comment #15 on top of the
previous patches.

Thanks,
Vlad

Created attachment 10866 [details]
Yet another debug patch to print device status

Looks bad. It seems the device is BUSY, but we need to confirm.

Mar 19 11:49:58 debian kernel: CDB (2:0,0,0) 28 00 00 00 e9 58 00 00 40
Mar 19 11:49:58 debian kernel: ata2: protocol 7 task_state 4
Mar 19 11:49:58 debian kernel: ata2: host_stat 0x4
Mar 19 11:49:58 debian kernel: ata2: protocol 7 task_state 4 (dev_stat 0x58)
Mar 19 11:50:03 debian kernel: ata2: protocol 7 task_state 2
Mar 19 11:50:03 debian kernel: ata2: host_stat 0x0
Mar 19 11:50:03 debian kernel: ata2: protocol 7 task_state 2
Mar 19 11:50:03 debian kernel: ata2: host_stat 0x0
Mar 19 11:50:03 debian kernel: ata2: protocol 7 task_state 2
Mar 19 11:50:03 debian kernel: ata2: host_stat 0x0
Mar 19 11:50:03 debian kernel: ata2: protocol 7 task_state 2

Could you please apply one more debug patch on top of the existing patches.
Thanks.

> Interestingly, Red Hat 9, which uses kernel 2.4.20, *can* mount and read
> from the CD. This leads me to believe that the error entered somewhere in
> the 2.6 branch.

Does RH9 read the full cd (ex. dd if=/dev/hdc | md5sum ) without problem?
Or, it can mount and read a few blocks like libata does, then somehow the cd-
rom drive stops working suddenly?

Created attachment 10867 [details]
Dmesg after applying patch from Comment #17

This is the dmesg after applying the patch from Comment #17 on top of the
existing patches.

> Does RH9 read the full cd (ex. dd if=/dev/hdc | md5sum ) without problem?
> Or, it can mount and read a few blocks like libata does, then somehow the cd-

> rom drive stops working suddenly?

RH9 can mount the CDs but eventually freezes when copying the RPMs from the CD
to the disk.

Thanks,
Vlad

> This is the dmesg after applying the patch from Comment #17 on 
> top of the existing patches.

Sorry I messed up the previous debug patch. Could you add "ap->id" to each of 
the printk() as shown below.

 	/* check altstatus */
 	status = ata_altstatus(ap);
+	if (ap->id == 2)
+		printk(KERN_ERR "ata%u: dev_altstatus 0x%X\n",
+		       ap->id, status);
+
 	if (status & ATA_BUSY)
 		goto idle_irq;
 
 	/* check main status, clearing INTRQ */
 	status = ata_chk_status(ap);
+	if (ap->id == 2)
+		printk(KERN_ERR "ata%u: dev_status 0x%X\n",
+		       ap->id, status);
 	if (unlikely(status & ATA_BUSY))
 		goto idle_irq;

> RH9 can mount the CDs but eventually freezes when copying the RPMs
> from the CD to the disk.

Hmm, that's exactly the same behavior we see with libata.

Maybe it the the "transfer length" that triggered the problem?

From the log, although the first read of 0x40 blocks of data successed:
  Mar 19 11:49:39 debian kernel: CDB (2:0,0,0) 28 00 00 00 00 00 00 00 40

Later the device choked when commands want to transfer 0x40 blocks of data:
  Mar 19 08:13:52 debian kernel: CDB (2:0,0,0) 28 00 00 00 eb 0e 00 00 40 
  ...
  Mar 19 11:49:58 debian kernel: CDB (2:0,0,0) 28 00 00 00 e9 58 00 00 40

Created attachment 10870 [details]
Possible fix to limit the max_sectors

Hi Vlad,

Could you please apply this max_sectors patch on top of existing patches and
see if it can avoid the TORiSAN DRD-N216 problem, thanks.

Created attachment 10878 [details]
Patch #23 makes the recurvise copy work!

Patch #23 on top of the previous patches makes the recursive copy work,
although I didn't let it run for too long because all the debug messages are
filling up the syslog. Will this be the final patch, or would you like me to
test new versions?

Thanks a lot for your help!
Vlad

Great, we have find out the secret recipe for the TORiSAN drive :)

> although I didn't let it run for too long because all the debug
> messages are filling up the syslog. 

We can remove the debugging code now. Please remove it or change the (ap->id == 
2) to (ap->id == 100).

> Will this be the final patch, or would you like me to
> test new versions?

We still have two more things to do:
1. Please gradually increase dev->max_sectors to find out the max safe value.

+	/* possbile workaround for TORiSAN */
+	if (dev->class == ATA_DEV_ATAPI) {
+		dev->max_sectors = 10;  => Increase from 10 to .. 56?
+	}
+

2. After we know the max safe vaule (say, 40) for the DMA mode, we must also 
make sure the same max safe vaule works under the PIO mode.
Please add back { "TORiSAN DVD-ROM DRD-N216", NULL,	ATA_HORKAGE_NODMA } to 
the dma blacklist and check if dev->max_sectors = (say, 40) also works under 
PIO mode. If not, we have to decrease it such that it works for both DMA and 
PIO.

After we know the max safe value, we can cook the final patch.

> 1. Please gradually increase dev->max_sectors to find out the max safe value.
>
> +	/* possbile workaround for TORiSAN */
> +	if (dev->class == ATA_DEV_ATAPI) {
> +		dev->max_sectors = 10;  => Increase from 10 to .. 56?
> +	}

Please wait a moment. The above method seems not good enough.
Sometimes the blocklayer sends smaller pieces of data. So, with the above 
method, it is not easy to know the real max value.

Maybe we can use sg_utils or something to issue "READ" to the device directly...
I will check if any utils can be used.

Ok, maybe sg_dd can be used to find the max safe value.

Please try:
1. Remove the following patch and rebuild the kernel.
+	/* possbile workaround for TORiSAN */
+	if (dev->class == ATA_DEV_ATAPI) {
+		dev->max_sectors = 10; 
+	}
+

2. Run something like below to read the disc:
"sg_dd blk_sgio=1 odir=1 if=/dev/sg1 bs=2048 count=160000 bpt=10|md5sum".
 We can gradually increase bpt from 10 to larger values and see what is the 
maximum safe value for the TORiSAN drive.

3. After we know the max safe value for DMA mode, add back the
  { "TORiSAN DVD-ROM DRD-N216", NULL,	ATA_HORKAGE_NODMA } entry to 
  the dma blacklist and repeat 2. (To make sure the max safe value also works 
for PIO mode.)

Just found this 
(http://www.linux-usb.org/FAQ.html#i5)
"... no trouble using 64 KB transfers (max_sectors = 128), and that's what 
Windows uses."

Hi Vlad,

Please ignore my comment #27.
Maybe we can just change the max sectors to 128 directly 

+	/* possbile workaround for TORiSAN */
+	if (dev->class == ATA_DEV_ATAPI) {
+		dev->max_sectors = 128;  <== Use 128 here
+	}
+

and perform recursive copy to see if "128" works for TORiSAN. Thanks.

Hi Vlad,

If dev->max_sectors = 128; ever works, please also try 
dev->max_sectors = 240;

Thanks.

(Adding Alan and Tejun to the cc list.)

Summary of problems found:
1. The TORiSAN drive cannot do ATAPI DMA for non-R/W command:
   ata2: protocol 7 task_state 4
   ata2: protocol 7 task_state 4 (dev_stat 0x58)
   ata2: protocol 7 task_state 2
   ata2: protocol 7 task_state 2 (dev_stat 0x58)
   ata2: protocol 7 task_state 3 (dev_stat 0x58)
   ata2.00: ata_eh_analyze_tf, AC_ERR_HSM, 0x58
   ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
   ata2.00: (BMDMA stat 0x5)
   ata2.00: cmd a0/01:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x12 data 36 in
            res 58/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x2 (HSM violation)

2. The TORiSAN drive locks up completely (hard reset needed)
   when reading 64 blocks of data:
   Mar 19 08:13:52 debian kernel: CDB (2:0,0,0) 28 00 00 00 eb 0e 00 00 40
   Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 4
   Mar 19 08:13:52 debian kernel: ata2: host_stat 0x4
   Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 4 (dev_stat 0x58)
   Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
   Mar 19 08:13:52 debian kernel: ata2: host_stat 0x1
   Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
   Mar 19 08:13:52 debian kernel: ata2: host_stat 0x1
   Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
   Mar 19 08:13:52 debian kernel: ata2: host_stat 0x0
   Mar 19 08:13:52 debian kernel: ata2: protocol 7 task_state 2
   Mar 19 08:13:52 debian kernel: ata2: host_stat 0x0

> If dev->max_sectors = 128; ever works, please also try dev->max_sectors =
> 240;

The following values work for max_sectors: 10, 128 and 240. The drive froze when
I set max_sectors to be 512 or 1024. Adding TORiSAN to the DMA blacklist yielded
the same results.

> The TORiSAN drive cannot do ATAPI DMA for non-R/W command

Indeed, patch #10 is required for the drive to initialize correctly during boot.
Does drivers/ide initialize the drive in DMA mode? Because I've not seen the
TORiSAN drive crash during initialization when using drivers/ide.

> The following values work for max_sectors: 10, 128 and 240. 
> The drive froze when I set max_sectors to be 512 or 1024. 

It seems 240 is the one to use. Currently libata set max_sectors
to 256 for non-LAB48 devices. So, 240 is quite close.

> Adding TORiSAN to the DMA blacklist yielded the same results.

Ok, so the max_sectors trick works for both PIO and DMA.

> ... patch #10 is required for the drive to initialize correctly
> during boot. Does drivers/ide initialize the drive in DMA mode? 
> Because  I've not seen the TORiSAN drive crash during initialization
> when using drivers/ide

The ToriSAN supports PIO4/MWDMA2. In drivers/ide, it is initiailzed to PIO4.
In libata, it is initiailzed to MWDMA2 to maxmize the performance.

Thanks for the info, patch to follow.

Created attachment 10928 [details]
Proposed patch

Hi Vlad,

Please try this patch on a clean kernel. (2.6.21-rcx would be nice.)

I am worried about the following code segment:
We didn't verify "READ_DVD_STRUCTURE" and "READ_CD" work under DMA mode yet.

+		case 0xad: /* READ_DVD_STRUCTURE */
+		case 0xbe: /* READ_CD */

Please try 
1. Do not add the TORiSAN drive to the DMA blacklist
2. Read from DVD media to verify 0xad works under DMA mode
3. Put in an audio CD and rip audio CD tracks to verify 0xbe under DMA mode

Thanks.

Created attachment 11017 [details]
Output of 'cdparanoia -vsQB >& cdparanoia.log'

I've applied the four patches posted at
http://article.gmane.org/gmane.linux.ide/17679 onto a fresh vanilla 2.6.21-rc5
kernel. However, I realized that 240 does _not_ work for max_sectors: when I
tried copying another (larger) CD of size 650 MB, it failed halfway through. 
Setting "ATA_MAX_SECTORS_240 = 128" works though, and I've tested this with 5
different data CDs (including the CD that failed when ATA_MAX_SECTORS_240 was
240).

Recursively copying two DVDs worked! 

I tried ripping two audio CDs using the same kernel as described above
(ATA_MAX_SECTORS_240 changed to 128), and I got the attached output when
running "cdparanoia -vsQB >& cdparanoia.log".

I noticed that in the patches submitted at
http://article.gmane.org/gmane.linux.ide/17679, "case 0xad: /*
READ_DVD_STRUCTURE */" and "case 0xbe: /* READ_CD */" were not included in the
switch statement. I added these to the switch statement, recompiled the kernel
and attempted again to copy the DVDs and rip the audio CDs.

Copying DVDs worked again!

Cdparanoia failed with the exact same output as before (please see attached
errors).

In conclusion, all data CDs and movie DVDs worked after changing
ATA_MAX_SECTORS_240 to 128. Reading DVDs works in both DMA and PIO mode.
Ripping audio CDs doesn't work in either mode.

PS: When booting in Windows 98, and I am able to listen to both audio CDs. I
was also able to rip both audio CDs using cdparanoia on a different computer.

Thank you for your help in fixing this drive!

Hi Vlad,

Thanks for the test. 
- I will revise the patch to use max_sect = 128.
- For the "case 0xad: case 0xbe:", I'm conservative about using ATAPI DMA for 
these commands. So, won't add them to the white list even if READ_DVD_STRUCTURE 
seems to work.
- For the cdparanoia rip audio track problem, maybe this is not libata problem. 
Please try if another rip application works.

> For the cdparanoia rip audio track problem, maybe this is not libata
> problem. Please try if another rip application works.

I got cdparanoia (and dcd) to work by first running "ln -s /dev/cdrom1
/dev/cdrom". For some reason, /dev/cdrom didn't exist before, but this could
just be a Debian issue...

> For the "case 0xad: case 0xbe:", I'm conservative about using ATAPI DMA
> for these commands. So, won't add them to the white list even if
> READ_DVD_STRUCTURE seems to work.

I was able to watch a full-length DVD movie with "case 0xad" using vlc, and not
a single error. Playback was visibly less choppy with "case 0xad" than without
it. I was also able to rip a whole music CD using cdparanoia with "case 0xbe".

Thanks again!

Hi Vlad,

The patch with updated max_sect = 128 and "using atapi dma only for r/w" has 
been accepted by Jeff; we can close this bug.

Good to know ATAPI DMA works for 0xad and 0xbe, but the patch has been 
accepted. If we can make sure that 0xad and 0xbe works for TORiSAN and all 
other drives that needs the "using atapi dma only for r/w" workaround, maybe we 
can add them back in the future.

Thanks.

Hi Vlad,

Recently Tejun has a new patch for ATAPI DMA. Could you please try if your TORiSAN DRD-N216 works ok after the new patch applied?

The patch to test:
https://bugzilla.novell.com/attachment.cgi?id=147389

(The bug: https://bugzilla.novell.com/show_bug.cgi?id=229260)

Hi Vlad,

Tejun's "use PIO for non-16 byte aligned ATAPI commands" patch has been accepted into 2.6.22-rc7 kernel. The ATAPI_DMA_RW_ONLY horkage has been removed. Could you please test your TORiSAN drive works with the new kernel, thanks!

Hi Albert,

Thank you very much for notifying me that ATAPI_DMA_RW_ONLY has been removed. I don't currently have the laptop that exhibited the problem, but I expect to get it back in a couple of weeks, at which time I will test a kernel newer than 2.6.22-rc7.

Thanks again!
Vlad