Re: Bug in mounting routines of atapi-cdroms

Gordon Chaffee (chaffee@cs.berkeley.edu)
Sun, 13 Sep 1998 23:02:37 -0700 (PDT)


Chris Ricker writes:
> Bill, I applied your most recent
> inode.c patches and switched back to the real ide driver from the ide ->
> scsi emulation driver. Here's the debugging output when I try to mount
> after bootup:
>
> /bin/mount -t iso9660 /dev/cdrom /mnt/cdrom -o ro
[parts of logs deleted]
> Sep 13 21:00:20 splat kernel: ISOFS: Forcing new log zone size:2048
> Sep 13 21:00:21 splat kernel: hdd: DMA disabled
> Sep 13 21:00:21 splat kernel: hdd: dma error: status=0x58 { DriveReady SeekComplete DataRequest }
> Sep 13 21:00:21 splat kernel: hdd: ATAPI reset complete
> Sep 13 21:00:21 splat kernel: ATAPI device hdd:
> Sep 13 21:00:21 splat kernel: Error: Unit attention -- (Sense key=0x06)
> Sep 13 21:00:21 splat kernel: Power on, reset or bus device reset occurred -- (asc=0x29, ascq=0x00)
>
> And, the mount process is infinitely hung....

OK, I'm beginning to see a possibility. The reason it isn't working
on the first attempt is because DMA to the cdrom is failing. See the
line that shows hdd: DMA disabled. For some reason, this is causing
the mount to hang entirely. My guess as to what is occurring is that
on a DMA failure and ATAPI reset, a request is getting lost somewhere
and not being reattempted after the transfer, but no error is getting
propagated upward.

> So, then I powered off and back on and tried things in the opposite order
> (dd and then mount). Here's the debugging output from that:
>
> /bin/dd if=/dev/cdrom of=/tmp/junk
> Sep 13 21:04:10 splat kernel: hdc: ATAPI 6X CDROM CD-R/RW drive, 1024kB Cache
> Sep 13 21:04:10 splat kernel: Uniform CDROM driver Revision: 2.13
> Sep 13 21:04:10 splat kernel: cdrom: drive "/dev/hdc" registered
> Sep 13 21:04:10 splat kernel: hdd: ATAPI 24X CDROM drive, 120kB Cache
> Sep 13 21:04:10 splat kernel: cdrom: drive "/dev/hdd" registered
> Sep 13 21:04:10 splat kernel: cdrom: entering cdrom_open
> Sep 13 21:04:10 splat kernel: cdrom: entering open_for_data
> Sep 13 21:04:10 splat kernel: cdrom: drive_status=4
> Sep 13 21:04:10 splat kernel: cdrom: entering cdrom_count_tracks
> Sep 13 21:04:10 splat kernel: cdrom: track 1: format=1, ctrl=4
> Sep 13 21:04:10 splat kernel: cdrom: disc has 1 tracks: 0=audio 1=data 0=Cd-I 0=XA
> Sep 13 21:04:10 splat kernel: cdrom: all seems well, opening the device.
> Sep 13 21:04:10 splat kernel: cdrom: opening the device gave me 0.
> Sep 13 21:04:10 splat kernel: cdrom: door locked.
> Sep 13 21:04:10 splat kernel: cdrom: device opened sucessfully.
> Sep 13 21:04:10 splat kernel: cdrom: Use count for "/dev/hdd" now 1
> Sep 13 21:04:12 splat kernel: hdd: DMA disabled
> Sep 13 21:04:12 splat kernel: hdd: dma error: status=0x58 { DriveReady SeekComplete DataRequest }
> Sep 13 21:04:12 splat kernel: hdd: ATAPI reset complete
> Sep 13 21:04:12 splat kernel: ATAPI device hdd:
> Sep 13 21:04:12 splat kernel: Error: Unit attention -- (Sense key=0x06)
> Sep 13 21:04:12 splat kernel: Power on, reset or bus device reset occurred -- (asc=0x29, ascq=0x00)
> Sep 13 21:04:22 splat kernel: cdrom: entering cdrom_release
> Sep 13 21:04:22 splat kernel: cdrom: Use count for "/dev/hdd" now zero
> Sep 13 21:04:22 splat kernel: cdrom: Unlocking door!
>
>
> The dd gives an error that looks like it should be hung, but it still
> manages to access the disk, judging from /tmp/junk.

Once again, the DMA is being disabled. However, this time the process
attempting it is dd, but dd doesn't seem to get hung. Can you do an
strace on the dd to see if any errors have been propagated to the top?
Additionally, I'd like to know if the actual data that gets transferred
is correct. As the first command after a boot, do a
strace -o/tmp/trace1 dd if=/dev/cdrom of=/tmp/junk1 bs=1024 count=2048
Then follow it up with
strace -o/tmp/trace2 dd if=/dev/cdrom of=/tmp/junk2 bs=1024 count=2048
and then
cmp /tmp/junk1 /tmp/junk2

> So, now I do a mount:
[ logs deleted]
> and it works! The stupid thing's acting like a soundcard that has to be
> tickled properly before it will work....

Yep, it works because by now, DMA is completely disabled. So the
disabling of DMA is causing a problem, but it didn't used to cause a
problem when the calling sequences in isofs/inode.c were different.

> Eliminating the ide cd driver completely by using the ide scsi emulation
> driver instead also solves the problem. That part suggests that the bug is
> in the ide-cdrom layer.

Or maybe the ide scsi emulation is not using DMA. Erik, what happens
to an outstanding request when an error occurs and the drive switches
over to not using DMA? From looking at the code, I don't see it
resending the request, but I'm not familiar with the code. in
ide-cd.c:cdrom_read_intr:805-823, I see the error condition occur.
and DMA get turned off. Under the normal condition, a call is then
made to ide_end_request(). In the error condition case,
a call is made to ide_error(), and for some requests, it is supposed
to retry. My guess is something isn't happening correctly in ide_error()
or one of the routines it is calling.

- Gordon

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/faq.html