Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 10 Oct 2002 22:34:18 -0600
From:      "Kenneth D. Merry" <ken@kdm.org>
To:        Kurt Seel <kseel@utcorp.com>
Cc:        freebsd-scsi <freebsd-scsi@FreeBSD.ORG>
Subject:   Re: pioneer DRM-600 problem
Message-ID:  <20021010223418.A53347@panzer.kdm.org>
In-Reply-To: <3DA60E3F.BA8A597A@utcorp.com>; from kseel@utcorp.com on Thu, Oct 10, 2002 at 07:33:19PM -0400
References:  <3D5B17A4.D2862CA6@utcorp.com> <3DA5CF94.6260EC18@utcorp.com> <20021010133409.A50349@panzer.kdm.org> <3DA60E3F.BA8A597A@utcorp.com>

next in thread | previous in thread | raw e-mail | index | archive | help
On Thu, Oct 10, 2002 at 19:33:19 -0400, Kurt Seel wrote:
> "Kenneth D. Merry" wrote:
> > On Thu, Oct 10, 2002 at 15:05:56 -0400, Kurt Seel wrote:
> > > Kurt Seel wrote:
> > > >
> > > >  I am using FBSD 4.5-stable.
> > > >  I have a Pioneer DRM-600. I passes the self diagnostic,
> > > > where to de-cable the unit, power off, flip switches 6 &
> > > > 8, then power on. It goes through loading each disc, then
> > > > ejects. Just like it should.
> > > >  When the machine boots, scans the unis and finds 6 cd devs,
> > > > dmesg output at the end of this message.
> > > >  But when I type :
> > > > chio status
> > > >  I get this :
> > > > chio: /dev/ch0: open: Device not configured
> > > >  So I made sure the devices were make, e.g.
> > > > cd /dev; ./MAKEDEV cd5; ./MAKEDEV ch0
> > > >  And :
> > > > mount -t cd9660 /dev/cd0c /conf/tmpmnt
> > > >  Gives me :
> > > > cd9660: /dev/cd0c: Device busy
> > > >
> > > >  I have tried it with evey permutation of option switches,
> > > > e.g. parity on, parity off ... no dice.
> > > >  Is there any hope for this unit? I'de really like to put
> > > > 6 CD's of mp3'ed music on a (atapi) cdrom booted (if you
> > > > look at the dmesg you'll see root is cd9660:acd0c - could
> > > > this be causing the problem?) network music server.
> > > >
> > >
> > >  I could not get this machine rebuilt, so I moved the device
> > > to another machine. Which 'sees' the device :
> > >
> > > New /dev > camcontrol devlist
> > > <TOSHIBA CD-ROM XM-6201TA 1030>    at scbus0 target 0 lun 0 (cd2,pass2)
> > > <YAMAHA CRW2200S 1.0D>             at scbus0 target 1 lun 0 (pass0,cd0)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 0 (cd1,pass1)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 1 (cd3,pass3)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 2 (cd4,pass4)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 3 (cd5,pass5)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 4 (cd6,pass6)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 5 (cd7,pass7)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 6 (pass8)
> > > <PIONEER CD-ROM DRM-600 0801>      at scbus0 target 6 lun 7 (pass9)
> > >
> > >  I have gotten musid CD's to play via xmcd (from ports) but I get
> > > the same 'device busy' when I try to mount (a data cd, storebought
> > > or home brew):
> > >
> > > New /root > mount -t cd9660 /dev/cd1c /cdrom1
> > > cd9660: /dev/cd1c: Device busy
> > 
> > Does anything show up in the dmesg?  If nothing shows up in the dmesg, try
> > booting with -v.
> 
>  A hell of alot, actually. I am not really sure what caused
> what so I'll include the whole mess:
> 
> cd1 at ahc0 bus 0 target 6 lun 0
> cd1: <PIONEER CD-ROM DRM-600 0801> Removable CD-ROM SCSI-CCS device
> cd1: 3.300MB/s transfers
> cd1: cd present [321646 x 2048 byte records]
> cd2 at ahc0 bus 0 target 0 lun 0
> cd2: <TOSHIBA CD-ROM XM-6201TA 1030> Removable CD-ROM SCSI-2 device
> cd2: 10.000MB/s transfers (10.000MHz, offset 15)
> cd2: cd present [261209 x 2048 byte records]
> cd3 at ahc0 bus 0 target 6 lun 1
> cd3: <PIONEER CD-ROM DRM-600 0801> Removable CD-ROM SCSI-CCS device
> cd3: 3.300MB/s transfers
> cd3: cd present [91407 x 2048 byte records]
> cd4 at ahc0 bus 0 target 6 lun 2
> cd4: <PIONEER CD-ROM DRM-600 0801> Removable CD-ROM SCSI-CCS device
> cd4: 3.300MB/s transfers
> cd4: cd present [332253 x 2048 byte records]
> cd5 at ahc0 bus 0 target 6 lun 3
> cd5: <PIONEER CD-ROM DRM-600 0801> Removable CD-ROM SCSI-CCS device
> cd5: 3.300MB/s transfers
> cd5: cd present [214998 x 2048 byte records]
> cd6 at ahc0 bus 0 target 6 lun 4
> cd6: <PIONEER CD-ROM DRM-600 0801> Removable CD-ROM SCSI-CCS device
> cd6: 3.300MB/s transfers
> cd6: cd present [331220 x 2048 byte records]
> cd7 at ahc0 bus 0 target 6 lun 5
> cd7: <PIONEER CD-ROM DRM-600 0801> Removable CD-ROM SCSI-CCS device
> cd7: 3.300MB/s transfers
> cd7: cd present [326103 x 2048 byte records]
> (cd8:ahc0:0:6:6): READ CD RECORDED CAPACITY. CDB: 25 c0 0 0 0 0 0 0 0 0
> (cd8:ahc0:0:6:6): ILLEGAL REQUEST asc:25,0
> (cd8:ahc0:0:6:6): Logical unit not supported
> (cd8:ahc0:0:6:6): fatal error, failed to attach to device
> (cd8:ahc0:0:6:6): lost device
> (cd8:ahc0:0:6:6): removing device entry
> (cd9:ahc0:0:6:7): READ CD RECORDED CAPACITY. CDB: 25 e0 0 0 0 0 0 0 0 0
> (cd9:ahc0:0:6:7): ILLEGAL REQUEST asc:25,0
> (cd9:ahc0:0:6:7): Logical unit not supported
> (cd9:ahc0:0:6:7): fatal error, failed to attach to device
> (cd9:ahc0:0:6:7): lost device
> (cd9:ahc0:0:6:7): removing device entry

Even though the device only has 6 LUNs, it looks like it is responding on
two more for some reason, and then rightly complaining when we try to
issue a read capacity to those LUNs.

> dscheck(#cd/18): b_bcount 512 is not on a sector boundary (ssize 2048)
> dscheck(#cd/18): b_bcount 512 is not on a sector boundary (ssize 2048)
> dscheck(#cd/18): b_bcount 512 is not on a sector boundary (ssize 2048)

This happens when you try to do 512-byte I/Os to a CDROM, which can only
handle 2048 byte I/Os.  This was probably when you tried dagrab.

> (pass5:ahc0:0:6:3): SCB 0x8 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

Hmm, here you timed out in Command phase.  This might be a cabling or
termination problem, or it may just be that the drive is locked up.

> (pass5:ahc0:0:6:3): BDR message in message buffer
> (pass5:ahc0:0:6:3): no longer in timeout, status = 300

Error recovery, we sent a BDR.

> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): MEDIUM ERROR info:51400 asc:15,0
> (cd2:ahc0:0:0:0): Random positioning error
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back

Now we get an error from a different LUN, but tagged as cd2, not a pass
device.  That's weird.

> (pass1:ahc0:0:6:0): SCB 0x2 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

And now a timeout in command phase on the pass device.  It looks like you
may have had things running at the same time via the passthrough and cd
interfaces.

> (pass1:ahc0:0:6:0): BDR message in message buffer
> (pass1:ahc0:0:6:0): no longer in timeout, status = 300

So now we send a BDR to that device.

> (pass6:ahc0:0:6:4): SCB 0x2 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

Another timeout on a different LUN.

> (pass6:ahc0:0:6:4): BDR message in message buffer
> (pass6:ahc0:0:6:4): no longer in timeout, status = 300

A BDR to recover.

> (pass6:ahc0:0:6:4): SCB 0x9 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

And another timeout on the same device.

> (pass6:ahc0:0:6:4): BDR message in message buffer
> (pass6:ahc0:0:6:4): no longer in timeout, status = 300

Again.

> (pass1:ahc0:0:6:0): SCB 0x2 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

Timeout on a different LUN.

> (pass1:ahc0:0:6:0): BDR message in message buffer
> (pass1:ahc0:0:6:0): no longer in timeout, status = 300

BDR to recover.

> (pass5:ahc0:0:6:3): SCB 0x8 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

Timeout on a different LUN.

> (pass5:ahc0:0:6:3): BDR message in message buffer
> (pass5:ahc0:0:6:3): no longer in timeout, status = 300

BDR to recover.

> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): MEDIUM ERROR info:51400 asc:15,0
> (cd2:ahc0:0:0:0): Random positioning error
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back

And again a medium error from the cd interface, not the pass interface.
There must have still been I/O going at this point.

> (pass7:ahc0:0:6:5): SCB 0x7 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

Timeout from a different LUN.

> (pass7:ahc0:0:6:5): BDR message in message buffer
> (pass7:ahc0:0:6:5): no longer in timeout, status = 300

BDR to recover.

> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): MEDIUM ERROR info:51400 asc:15,0
> (cd2:ahc0:0:0:0): Random positioning error
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back
> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): MEDIUM ERROR info:51400 asc:15,0
> (cd2:ahc0:0:0:0): Random positioning error
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back

More medium errors from the cd interface.

> (pass6:ahc0:0:6:4): SCB 0x2 - timed out
> ahc0: Dumping Card State in Command phase, at SEQADDR 0x15c

Timeout from another LUN.

> (pass6:ahc0:0:6:4): BDR message in message buffer
> (pass6:ahc0:0:6:4): no longer in timeout, status = 300

BDR to recover.

> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): BLANK CHECK asc:64,0
> (cd2:ahc0:0:0:0): Illegal mode for this track
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back

Interesting, my guess is that this was caused by dagrab.

[ ... ]

> (pass1:ahc0:0:6:0): BDR message in message buffer
> (pass1:ahc0:0:6:0): no longer in timeout, status = 34c
> dscheck(#cd/18): b_bcount 512 is not on a sector boundary (ssize 2048)
> dscheck(#cd/2): b_bcount 512 is not on a sector boundary (ssize 2048)
> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): MEDIUM ERROR info:51400 asc:15,0
> (cd2:ahc0:0:0:0): Random positioning error
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back
> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): MEDIUM ERROR info:51400 asc:15,0
> (cd2:ahc0:0:0:0): Random positioning error
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back
> (cd2:ahc0:0:0:0): READ(10). CDB: 28 0 0 5 14 0 0 0 1 0
> (cd2:ahc0:0:0:0): MEDIUM ERROR info:51400 asc:15,0
> (cd2:ahc0:0:0:0): Random positioning error
> (cd2:ahc0:0:0:0): cddone: got error 0x5 back

That too.

> New /usr/home/kseel/scans/halloween >
> 
> > 
> > What happens when you do:
> > 
> > camcontrol tur cd1 -v
> > 
> > Do it a couple of times.  Then try:
> > 
> > camcontrol cmd cd1 -v -c "25 0 0 0 0 0 0 0 0 0" -i 8 "i4 i4"
> > 
> 
> New /new2/usr3 > camcontrol tur cd1 -v
> Unit is ready
> New /new2/usr3 >
> New /new2/usr3 > camcontrol tur cd1 -v
> Unit is ready
> New /new2/usr3 > camcontrol tur cd1 -v
> Unit is ready
> New /new2/usr3 > camcontrol cmd cd1 -v -c "25 0 0 0 0 0 0 0 0 0" -i 8 "i4 i4"
> 201000 2048

Looks right.

> New /new2/usr3 >
> 
>  
> > >  Also, dagrab just hangs :
> > >
> > > dagrab -d /dev/cd4c @TRK_dire_straights
> > >
> > >  Uninterruptably too, e.g. ^C, ^\, ^Z no workee.
> > 
> > dagrab is for ATAPI CDROM drives, not SCSI.  You need to use cdda2wav or
> > tosha to grab audio tracks off the drive, assuming one of them supports
> > that drive.
> 
>  D'oh!
>  cdda2wav does this :
> 
> New /root > cdda2wav -D 0,6,0
> Type: ROM, Vendor 'PIONEER ' Model 'CD-ROM DRM-600  ' Revision '0801' no MMC
> 266240 bytes buffer memory requested, 4 buffers, 27 sectors
> cdda2wav: Input/output error. read toc size: scsi sendcmd: retryable error
> CDB:  43 00 00 00 00 00 01 00 04 00
> status: 0x2 (CHECK CONDITION)
> Sense Bytes: 70 00 05 00 00 00 00 08 00 00 00 00 20 00 00 00
> Sense Key: 0x5 Illegal Request, Segment 0
> Sense Code: 0x20 Qual 0x00 (invalid command operation code) Fru 0x0
> Sense flags: Blk 0 (not valid)
> resid: 4
> cmd finished after 0.002s timeout 300s
> Read TOC size failed.

It looks like cdda2wav is trying to read the TOC, and the drive is saying
it doesn't support that command.

That's rather odd, although I suppose it's possible that the SCSI-1 spec
didn't really have a provision for reading the table of contents, although
that seems rather odd.  It is an optional command in SCSI-2.

Okay, here's something more to try:

 - reboot the machine
 - try mounting a data disk in the drive, and send the dmesg output that
   happens from doing that and only that.

There's a lot of stuff up there, and it's difficult to tell what was caused
by dagrab or anything else.

Ken
-- 
Kenneth Merry
ken@kdm.org

To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-scsi" in the body of the message




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20021010223418.A53347>