Re: Bug in mounting routines of atapi-cdroms

Chris Ricker (kaboom@gatech.edu)
Mon, 14 Sep 1998 01:04:42 -0400 (EDT)


<CC'ed to linux-kernel since Erik and Andre might be interested, not to
mention the three or four people experiencing similar hangs....>

On Sun, 13 Sep 1998, Gordon Chaffee wrote:

> Bill Hawes writes:
> > Chris has a case where enabling IDE DMA causes a hang, but without DMA
> > it works. I don't see how anything in isofs/inode.c could affect DMA,
> > but there may be some subtle interaction with timing.
>
> I'd be interested in seeing if just accessing the cdrom causes the problem
> without involving the isofs code at all. Chris, can you do a
>
> dd if=/dev/cdrom of=/dev/null
>
> and see if that hangs the machine? I'd like to see if we can eliminate
> the isofs code from the picture since I really suspect the issue is
> coming from somewhere else. I notice that there were changes to
> block/ide.c in the 101 and 102 patches, so they could have had an
> impact.

Thanks guys for your suggestions.

Gordon, to bring you up to speed completely, my box doesn't hang. The mount
process hangs. The bug first appeared in 2.1.117 (I don't use cd-roms very
often, obviously), so I worked forward from 2.1.96 which was the previous
one I'd used a cd with. What I found was that 2.1.101 and previous were
fine. The first time I try to mount a cd on those after bootup, the mount
returns an error and then all subsequent mounts would work (which is also
what 2.0.x does on that box with that cdrom). Starting with 2.1.102, the
initial mount after bootup hangs infinitely, making subsequent mount
attempts impossible (though I suspect they would work). I worked throught
the 101 and 102 patches file-change by file-change, and it's definitely the
fs/isofs/inode.c changes that are breaking things. 2.1.102 with only the
2.1.102 inode.c changes backed out works fine, and 2.1.101 with just 2.1.102
inode.c changes added breaks. I don't think it's actually the inode.c
rearrangement per se, but rather an overly sensitive DMA and a not-quite
compliant (or perhaps even compliant, but closer to the edge than the Linux
DMA code expects) cdrom. Furthermore, I now have another ide cd-rw on that
same bus, and it works great with all kernels and with or without dma, so
it's probably not that my bus is broken.

Now, for the latest round of tests. 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:

Sep 13 21:00:18 splat sudo: kaboom : TTY=tty1 ; PWD=/home/kaboom ; USER=root ; COMMAND=/bin/mount -t iso9660 /dev/cdrom /mnt/cdrom -o ro
Sep 13 21:00:18 splat kernel: hdc: ATAPI 6X CDROM CD-R/RW drive, 1024kB Cache
Sep 13 21:00:18 splat kernel: Uniform CDROM driver Revision: 2.13
Sep 13 21:00:18 splat kernel: cdrom: drive "/dev/hdc" registered
Sep 13 21:00:18 splat kernel: hdd: ATAPI 24X CDROM drive, 120kB Cache
Sep 13 21:00:18 splat kernel: cdrom: drive "/dev/hdd" registered
Sep 13 21:00:18 splat kernel: cdrom: entering cdrom_open
Sep 13 21:00:18 splat kernel: cdrom: entering open_for_data
Sep 13 21:00:18 splat kernel: cdrom: drive_status=4
Sep 13 21:00:18 splat kernel: cdrom: entering cdrom_count_tracks
Sep 13 21:00:18 splat kernel: cdrom: track 1: format=1, ctrl=4
Sep 13 21:00:18 splat kernel: cdrom: disc has 1 tracks: 0=audio 1=data 0=Cd-I 0=XA
Sep 13 21:00:18 splat kernel: cdrom: all seems well, opening the device.
Sep 13 21:00:18 splat kernel: cdrom: opening the device gave me 0.
Sep 13 21:00:18 splat kernel: cdrom: door locked.
Sep 13 21:00:18 splat kernel: cdrom: device opened sucessfully.
Sep 13 21:00:18 splat kernel: cdrom: Use count for "/dev/hdd" now 1
Sep 13 21:00:18 splat kernel: cdrom: entering CDROMMULTISESSION
Sep 13 21:00:18 splat kernel: cdrom: CDROMMULTISESSION sucessful
Sep 13 21:00:18 splat kernel: isofs_read_super: last session start=0
Sep 13 21:00:20 splat kernel: isofs_read_super: read block=32, blksize=1024
Sep 13 21:00:20 splat kernel: isofs_read_super: saving pri, pri_bh=c3a06740, pri=c34c0400
Sep 13 21:00:20 splat kernel: isofs_read_super: read block=34, blksize=1024
Sep 13 21:00:20 splat kernel: isofs_read_super: read block=36, blksize=1024
Sep 13 21:00:20 splat kernel: isofs_read_super: using pri=c34c0400, got rootp=c34c049c
Sep 13 21:00:20 splat kernel: Max size:326502 Log zone size:2048
Sep 13 21:00:20 splat kernel: First datazone:39 Root inode number:79872
Sep 13 21:00:20 splat kernel: isofs_read_super: releasing bh=c3a06740
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.... At this point, I can do a dd
if=/dev/cdrom of=/tmp/junk (cdrom is a symlink to hdd, the flaky cdrom;
also, Gordon, you have to send the output to a real file, because sending it
to /dev/null is indistinguishable w/o using strace from a hung disk access)
and that dd actually accesses the device.

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:

Sep 13 21:04:10 splat sudo: kaboom : TTY=tty1 ; PWD=/home/kaboom ; USER=root ; COMMAND=/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.

So, now I do a mount:

Sep 13 21:05:07 splat sudo: kaboom : TTY=tty1 ; PWD=/home/kaboom ; USER=root ; COMMAND=/bin/mount -t iso9660 /dev/cdrom /mnt/cdrom -o ro
Sep 13 21:05:08 splat kernel: cdrom: entering cdrom_open
Sep 13 21:05:08 splat kernel: cdrom: entering open_for_data
Sep 13 21:05:08 splat kernel: cdrom: drive_status=4
Sep 13 21:05:08 splat kernel: cdrom: entering cdrom_count_tracks
Sep 13 21:05:08 splat kernel: cdrom: track 1: format=1, ctrl=4
Sep 13 21:05:08 splat kernel: cdrom: disc has 1 tracks: 0=audio 1=data 0=Cd-I 0=XA
Sep 13 21:05:08 splat kernel: cdrom: all seems well, opening the device.
Sep 13 21:05:08 splat kernel: cdrom: opening the device gave me 0.
Sep 13 21:05:08 splat kernel: cdrom: door locked.
Sep 13 21:05:08 splat kernel: cdrom: device opened sucessfully.
Sep 13 21:05:08 splat kernel: cdrom: Use count for "/dev/hdd" now 1
Sep 13 21:05:08 splat kernel: cdrom: entering CDROMMULTISESSION
Sep 13 21:05:08 splat kernel: cdrom: CDROMMULTISESSION sucessful
Sep 13 21:05:08 splat kernel: isofs_read_super: last session start=0
Sep 13 21:05:10 splat kernel: isofs_read_super: read block=32, blksize=1024
Sep 13 21:05:10 splat kernel: isofs_read_super: saving pri, pri_bh=c1424000, pri=c1425400
Sep 13 21:05:10 splat kernel: isofs_read_super: read block=34, blksize=1024
Sep 13 21:05:11 splat kernel: isofs_read_super: read block=36, blksize=1024
Sep 13 21:05:11 splat kernel: isofs_read_super: using pri=c1425400, got rootp=c142549c
Sep 13 21:05:11 splat kernel: Max size:326502 Log zone size:2048
Sep 13 21:05:11 splat kernel: First datazone:39 Root inode number:79872
Sep 13 21:05:11 splat kernel: isofs_read_super: releasing bh=c1424000
Sep 13 21:05:11 splat kernel: ISOFS: Forcing new log zone size:2048

and it works! The stupid thing's acting like a soundcard that has to be
tickled properly before it will work....

I suspect that there's a small timing problem with the dma and the real ide
cdrom driver interacting with isofs. Once you've "initialized" it (which
doesn't particularly make sense for a cd-rom drive, but hey) by the dd, the
isofs is fine. If you haven't "initialized" it, it hangs. This part
suggests problems with the dma code, isofs layer, or the device.

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.

It's kinda a tricky thing to isolate ;-). I'm happy now since the scsi
stuff which I need for my shiny new CD-RW (hey Erik, if you want one to play
with, the Future Shop going-out-of-business sale is a Good Thing) solves the
problem, as does using the normal ide driver and doing an initial dd, but
there's some quirk lurking in the code someplace.

later,
chris

-
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