2004-01-02 08:40:22

by Jeff Chua

[permalink] [raw]
Subject: GetASF failed on DVD authentication


Got the following error while authenticating DVD ...

GetASF failed
N/A, invalidating: Function not implemented
N/A, invalidating: Function not implemented
N/A, invalidating: Function not implemented
Request AGID [1]... Request AGID [2]... Request AGID [3]...
Cannot get AGID


This error happens only on USB DVD drive using /dev/scd0 ...

Linux version is 2.4.24-pre3.


Module Size Used by Tainted: P
ehci-hcd 15368 0 (unused)
usb-storage 23800 0
usbcore 56672 1 [ehci-hcd usb-storage]
ds 6504 2
yenta_socket 9568 2
isofs 17580 0 (autoclean)
loop 8408 0 (autoclean)
sr_mod 12560 0 (autoclean)
cdrom 27296 0 (autoclean) [sr_mod]
scsi_mod 86472 2 (autoclean) [usb-storage sr_mod]



Problem does not happen on _real_ IDE DVD drive (/dev/hdc). Could it be
something to do with usb-storage or the sg module? Looks like the code
does not implement the DVD_LU_SEND_ASF DVD_AUTH ioctl?

Is there a patch for this?

Thanks.


2004-01-02 10:40:12

by Jens Axboe

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication

On Fri, Jan 02 2004, Jeff Chua wrote:
>
> Got the following error while authenticating DVD ...
>
> GetASF failed
> N/A, invalidating: Function not implemented
> N/A, invalidating: Function not implemented
> N/A, invalidating: Function not implemented
> Request AGID [1]... Request AGID [2]... Request AGID [3]...
> Cannot get AGID
>
>
> This error happens only on USB DVD drive using /dev/scd0 ...
>
> Linux version is 2.4.24-pre3.
>
>
> Module Size Used by Tainted: P
> ehci-hcd 15368 0 (unused)
> usb-storage 23800 0
> usbcore 56672 1 [ehci-hcd usb-storage]
> ds 6504 2
> yenta_socket 9568 2
> isofs 17580 0 (autoclean)
> loop 8408 0 (autoclean)
> sr_mod 12560 0 (autoclean)
> cdrom 27296 0 (autoclean) [sr_mod]
> scsi_mod 86472 2 (autoclean) [usb-storage sr_mod]
>
>
>
> Problem does not happen on _real_ IDE DVD drive (/dev/hdc). Could it be
> something to do with usb-storage or the sg module? Looks like the code
> does not implement the DVD_LU_SEND_ASF DVD_AUTH ioctl?

sr passes those ioctls through, or rather the uniform layer handles
them.

I can't say what goes wrong from the info above. Do you get any kernel
messages?

> Is there a patch for this?

Good one ;) Please make a proper bug report, you don't even include
drive info.

--
Jens Axboe

2004-01-02 14:27:13

by Jeff Chua

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication


On Fri, 2 Jan 2004, Jens Axboe wrote:

> > GetASF failed
> > N/A, invalidating: Function not implemented
> > N/A, invalidating: Function not implemented
> > N/A, invalidating: Function not implemented
> > Request AGID [1]... Request AGID [2]... Request AGID [3]...
> > Cannot get AGID


> > This error happens only on USB DVD drive using /dev/scd0 ...

USB drive is a Pioneer DVR-SK11B-J. It's reported as ...

scsi0 : SCSI emulation for USB Mass Storage devices
Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
Type: CD-ROM ANSI SCSI revision: 02

I've tried at least 2 other USB drives (Plextor PX-208U, and Sony CRX85U),
and both of these drives also exhibit the same problem.


> > Linux version is 2.4.24-pre3.


> I can't say what goes wrong from the info above. Do you get any kernel
> messages?

No kernels oops. Just those "GetASF failed" messages above.

Detailed dmesg as follows ...

Yenta ISA IRQ mask 0x0638, PCI irq 11
Socket status: 30000820
Yenta ISA IRQ mask 0x0638, PCI irq 11
Socket status: 30000006
cs: cb_alloc(bus 2): vendor 0x1033, device 0x0035
PCI: Enabling device 02:00.0 (0000 -> 0002)
PCI: Enabling device 02:00.1 (0000 -> 0002)
PCI: Enabling device 02:00.2 (0000 -> 0002)
cs: IO port probe 0x0100-0x03ff: excluding 0x170-0x177 0x370-0x37f
cs: IO port probe 0x0a20-0x0a27: clean.
usb.c: registered new driver usbdevfs
usb.c: registered new driver hub
Initializing USB Mass Storage driver...
usb.c: registered new driver usb-storage
USB Mass Storage support registered.
ehci_hcd 02:00.2: PCI device 1033:00e0
ehci_hcd 02:00.2: irq 11, pci mem f969b000
usb.c: new USB bus registered, assigned bus number 1
ehci_hcd 02:00.2: USB 2.0 enabled, EHCI 1.00, driver 2003-Jun-19/2.4
hub.c: USB hub found
hub.c: 3 ports detected
hub.c: new USB device 02:00.2-1, assigned address 2
scsi0 : SCSI emulation for USB Mass Storage devices
Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
Type: CD-ROM ANSI SCSI revision: 02
Attached scsi CD-ROM sr0 at scsi0, channel 0, id 0, lun 0
sr0: scsi-1 drive
Uniform CD-ROM driver Revision: 3.12
WARNING: USB Mass Storage data integrity not assured
USB Mass Storage device found at 2


Thanks,
Jeff

2004-01-02 14:38:20

by Jens Axboe

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication

On Fri, Jan 02 2004, Jeff Chua wrote:
>
> On Fri, 2 Jan 2004, Jens Axboe wrote:
>
> > > GetASF failed
> > > N/A, invalidating: Function not implemented
> > > N/A, invalidating: Function not implemented
> > > N/A, invalidating: Function not implemented
> > > Request AGID [1]... Request AGID [2]... Request AGID [3]...
> > > Cannot get AGID
>
>
> > > This error happens only on USB DVD drive using /dev/scd0 ...
>
> USB drive is a Pioneer DVR-SK11B-J. It's reported as ...
>
> scsi0 : SCSI emulation for USB Mass Storage devices
> Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
> Type: CD-ROM ANSI SCSI revision: 02
>
> I've tried at least 2 other USB drives (Plextor PX-208U, and Sony CRX85U),
> and both of these drives also exhibit the same problem.
>
>
> > > Linux version is 2.4.24-pre3.
>
>
> > I can't say what goes wrong from the info above. Do you get any kernel
> > messages?
>
> No kernels oops. Just those "GetASF failed" messages above.

I forget which, but there's an option to make usb-storage dump all
commands going through it. If you could enable that and send the
results, that would help a lot.


--
Jens Axboe

2004-01-02 16:12:22

by Michael Hunold

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication

diff -ur linux-2.4.21/drivers/scsi/sr.c linux-2.4.21.patched/drivers/scsi/sr.c
--- linux-2.4.21/drivers/scsi/sr.c 2003-06-13 16:51:36.000000000 +0200
+++ linux-2.4.21.patched/drivers/scsi/sr.c 2003-08-27 23:52:32.000000000 +0200
@@ -725,7 +725,7 @@
/* failed, drive doesn't have capabilities mode page */
scsi_CDs[i].cdi.speed = 1;
scsi_CDs[i].cdi.mask |= (CDC_CD_R | CDC_CD_RW | CDC_DVD_R |
- CDC_DVD | CDC_DVD_RAM |
+ /* USB-DVD-SCSI-2 hack: */ /* CDC_DVD | */ CDC_DVD_RAM |
CDC_SELECT_DISC | CDC_SELECT_SPEED);
scsi_free(buffer, 512);
printk("sr%i: scsi-1 drive\n", i);


Attachments:
usb-scsi-2-dvd.patch (606.00 B)

2004-01-02 16:18:32

by Jens Axboe

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication

On Fri, Jan 02 2004, Michael Hunold wrote:
> Helloo
>
> On 02.01.2004 15:25, Jeff Chua schrieb:
> >On Fri, 2 Jan 2004, Jens Axboe wrote:
>
> >USB drive is a Pioneer DVR-SK11B-J. It's reported as ...
> >
> >scsi0 : SCSI emulation for USB Mass Storage devices
> > Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
> > Type: CD-ROM ANSI SCSI revision: 02
> >
> >I've tried at least 2 other USB drives (Plextor PX-208U, and Sony CRX85U),
> >and both of these drives also exhibit the same problem.
>
> >>>Linux version is 2.4.24-pre3.
>
> >scsi0 : SCSI emulation for USB Mass Storage devices
> > Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
> > Type: CD-ROM ANSI SCSI revision: 02
> >Attached scsi CD-ROM sr0 at scsi0, channel 0, id 0, lun 0
> >sr0: scsi-1 drive
>
> IMHO the problem is inside SCSI drive recognition system, which can be
> found in "drivers/scsi/sr.c".
>
> The function "get_capabilities()" tries to find out which type of drive
> you have.
>
> ---------------------------schnipp--------------------------------------
> rc = sr_do_ioctl(i, cmd, buffer, 128, 1, SCSI_DATA_READ, NULL);
>
> if (rc) {
> /* failed, drive doesn't have capabilities mode page */
> scsi_CDs[i].cdi.speed = 1;
> scsi_CDs[i].cdi.mask |= (CDC_CD_R | CDC_CD_RW | CDC_DVD_R |
> CDC_DVD | CDC_DVD_RAM |
> CDC_SELECT_DISC | CDC_SELECT_SPEED);
> scsi_free(buffer, 512);
> printk("sr%i: scsi-1 drive\n", i);
> return;
> }
> ---------------------------schnipp--------------------------------------
>
> For my SCSI-2/USB drive, the above SCSI_DATA_READ command fails. As you
> can see, in this case the driver thinks that your drive is SCSI-1, ie. a
> CD-drive only. So DVD ioctls like the AGID commands will be filtered in
> the lower levels, because a CD-driver does not understand them anyway.
>
> Unfortunately, the driver only knows SCSI-1 and SCSI-3, so SCSI-2 DVD
> driver are out of luck here and get downgraded to SCSI-1 CD-ROM stuff.
>
> The patch below unmasks the DVD drive bit, ie. even if the kernel
> misdetects your driver, it will allow DVD ioctls to be passed to your drive.
>
> This is not a safe fix, but "it works for me"(tm). I don't know how to
> really fix it; probably adding proper SCSI-2 support.
>
> >Thanks,
> >Jeff
>
> CU
> Michael.

> diff -ur linux-2.4.21/drivers/scsi/sr.c linux-2.4.21.patched/drivers/scsi/sr.c
> --- linux-2.4.21/drivers/scsi/sr.c 2003-06-13 16:51:36.000000000 +0200
> +++ linux-2.4.21.patched/drivers/scsi/sr.c 2003-08-27 23:52:32.000000000 +0200
> @@ -725,7 +725,7 @@
> /* failed, drive doesn't have capabilities mode page */
> scsi_CDs[i].cdi.speed = 1;
> scsi_CDs[i].cdi.mask |= (CDC_CD_R | CDC_CD_RW | CDC_DVD_R |
> - CDC_DVD | CDC_DVD_RAM |
> + /* USB-DVD-SCSI-2 hack: */ /* CDC_DVD | */ CDC_DVD_RAM |
> CDC_SELECT_DISC | CDC_SELECT_SPEED);
> scsi_free(buffer, 512);
> printk("sr%i: scsi-1 drive\n", i);

Better yet, kill the silly checks instead.

===== drivers/cdrom/cdrom.c 1.41 vs edited =====
--- 1.41/drivers/cdrom/cdrom.c Sat Sep 27 16:24:59 2003
+++ edited/drivers/cdrom/cdrom.c Fri Jan 2 17:17:47 2004
@@ -2094,8 +2094,6 @@
case DVD_READ_STRUCT: {
dvd_struct *s;
int size = sizeof(dvd_struct);
- if (!CDROM_CAN(CDC_DVD))
- return -ENOSYS;
if ((s = (dvd_struct *) kmalloc(size, GFP_KERNEL)) == NULL)
return -ENOMEM;
cdinfo(CD_DO_IOCTL, "entering DVD_READ_STRUCT\n");
@@ -2115,8 +2113,6 @@

case DVD_AUTH: {
dvd_authinfo ai;
- if (!CDROM_CAN(CDC_DVD))
- return -ENOSYS;
cdinfo(CD_DO_IOCTL, "entering DVD_AUTH\n");
IOCTL_IN(arg, dvd_authinfo, ai);
if ((ret = dvd_do_auth (cdi, &ai)))


--
Jens Axboe

2004-01-02 16:30:41

by Jens Axboe

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication

On Fri, Jan 02 2004, Jens Axboe wrote:
> On Fri, Jan 02 2004, Michael Hunold wrote:
> > Helloo
> >
> > On 02.01.2004 15:25, Jeff Chua schrieb:
> > >On Fri, 2 Jan 2004, Jens Axboe wrote:
> >
> > >USB drive is a Pioneer DVR-SK11B-J. It's reported as ...
> > >
> > >scsi0 : SCSI emulation for USB Mass Storage devices
> > > Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
> > > Type: CD-ROM ANSI SCSI revision: 02
> > >
> > >I've tried at least 2 other USB drives (Plextor PX-208U, and Sony CRX85U),
> > >and both of these drives also exhibit the same problem.
> >
> > >>>Linux version is 2.4.24-pre3.
> >
> > >scsi0 : SCSI emulation for USB Mass Storage devices
> > > Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
> > > Type: CD-ROM ANSI SCSI revision: 02
> > >Attached scsi CD-ROM sr0 at scsi0, channel 0, id 0, lun 0
> > >sr0: scsi-1 drive
> >
> > IMHO the problem is inside SCSI drive recognition system, which can be
> > found in "drivers/scsi/sr.c".
> >
> > The function "get_capabilities()" tries to find out which type of drive
> > you have.
> >
> > ---------------------------schnipp--------------------------------------
> > rc = sr_do_ioctl(i, cmd, buffer, 128, 1, SCSI_DATA_READ, NULL);
> >
> > if (rc) {
> > /* failed, drive doesn't have capabilities mode page */
> > scsi_CDs[i].cdi.speed = 1;
> > scsi_CDs[i].cdi.mask |= (CDC_CD_R | CDC_CD_RW | CDC_DVD_R |
> > CDC_DVD | CDC_DVD_RAM |
> > CDC_SELECT_DISC | CDC_SELECT_SPEED);
> > scsi_free(buffer, 512);
> > printk("sr%i: scsi-1 drive\n", i);
> > return;
> > }
> > ---------------------------schnipp--------------------------------------
> >
> > For my SCSI-2/USB drive, the above SCSI_DATA_READ command fails. As you
> > can see, in this case the driver thinks that your drive is SCSI-1, ie. a
> > CD-drive only. So DVD ioctls like the AGID commands will be filtered in
> > the lower levels, because a CD-driver does not understand them anyway.
> >
> > Unfortunately, the driver only knows SCSI-1 and SCSI-3, so SCSI-2 DVD
> > driver are out of luck here and get downgraded to SCSI-1 CD-ROM stuff.
> >
> > The patch below unmasks the DVD drive bit, ie. even if the kernel
> > misdetects your driver, it will allow DVD ioctls to be passed to your drive.
> >
> > This is not a safe fix, but "it works for me"(tm). I don't know how to
> > really fix it; probably adding proper SCSI-2 support.
> >
> > >Thanks,
> > >Jeff
> >
> > CU
> > Michael.
>
> > diff -ur linux-2.4.21/drivers/scsi/sr.c linux-2.4.21.patched/drivers/scsi/sr.c
> > --- linux-2.4.21/drivers/scsi/sr.c 2003-06-13 16:51:36.000000000 +0200
> > +++ linux-2.4.21.patched/drivers/scsi/sr.c 2003-08-27 23:52:32.000000000 +0200
> > @@ -725,7 +725,7 @@
> > /* failed, drive doesn't have capabilities mode page */
> > scsi_CDs[i].cdi.speed = 1;
> > scsi_CDs[i].cdi.mask |= (CDC_CD_R | CDC_CD_RW | CDC_DVD_R |
> > - CDC_DVD | CDC_DVD_RAM |
> > + /* USB-DVD-SCSI-2 hack: */ /* CDC_DVD | */ CDC_DVD_RAM |
> > CDC_SELECT_DISC | CDC_SELECT_SPEED);
> > scsi_free(buffer, 512);
> > printk("sr%i: scsi-1 drive\n", i);
>
> Better yet, kill the silly checks instead.

BTW Jeff, I'd still very much like to see the usb-storage log from when
sr gets loaded. Even though it's fine to kill the CDC_DVD checks, it
would still be a good idea to fix why the capabilities check fails. That
is the real bug.


--
Jens Axboe

2004-01-03 00:49:20

by Jeff Chua

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication


On Fri, 2 Jan 2004, Jens Axboe wrote:

> BTW Jeff, I'd still very much like to see the usb-storage log from when
> sr gets loaded. Even though it's fine to kill the CDC_DVD checks, it
> would still be a good idea to fix why the capabilities check fails. That
> is the real bug.

Below is the "debug" messages for usb-storage ...

The log showed "Illegal Request: invalid command operation code" when I
issued "tstdvd".


Thanks,
Jeff


********* starting usb ...
Jan 3 08:11:07 boston kernel: PCI: Setting latency timer of device 00:1f.6 to 64
Jan 3 08:11:33 boston kernel: PCI: Setting latency timer of device 00:1d.0 to 64
Jan 3 08:11:34 boston kernel: usb.c: kmalloc IF f6d8a280, numif 1
Jan 3 08:11:34 boston kernel: usb.c: new device strings: Mfr=0, Product=2, SerialNumber=1
Jan 3 08:11:34 boston kernel: usb.c: USB device number 1 default language ID 0x0
Jan 3 08:11:34 boston kernel: hub.c: standalone hub
Jan 3 08:11:34 boston kernel: hub.c: ganged power switching
Jan 3 08:11:34 boston kernel: hub.c: global over-current protection
Jan 3 08:11:34 boston kernel: hub.c: Port indicators are not supported
Jan 3 08:11:34 boston kernel: hub.c: power on to power good time: 2ms
Jan 3 08:11:34 boston kernel: hub.c: hub controller current requirement: 0mA
Jan 3 08:11:34 boston kernel: hub.c: port removable status: RR
Jan 3 08:11:34 boston kernel: hub.c: local power source is good
Jan 3 08:11:34 boston kernel: hub.c: no over-current condition exists
Jan 3 08:11:34 boston kernel: hub.c: enabling power on all ports
Jan 3 08:11:34 boston kernel: usb.c: hub driver claimed interface f6d8a280
Jan 3 08:11:34 boston kernel: usb.c: kusbd: /sbin/hotplug add 1
Jan 3 08:11:34 boston kernel: usb.c: kusbd policy returned 0xfffffffe
Jan 3 08:11:34 boston kernel: PCI: Setting latency timer of device 00:1d.1 to 64
Jan 3 08:11:34 boston kernel: usb.c: kmalloc IF f6d8a3a0, numif 1
Jan 3 08:11:34 boston kernel: usb.c: new device strings: Mfr=0, Product=2, SerialNumber=1
Jan 3 08:11:34 boston kernel: usb.c: USB device number 1 default language ID 0x0
Jan 3 08:11:34 boston kernel: hub.c: standalone hub
Jan 3 08:11:34 boston kernel: hub.c: ganged power switching
Jan 3 08:11:34 boston kernel: hub.c: global over-current protection
Jan 3 08:11:34 boston kernel: hub.c: Port indicators are not supported
Jan 3 08:11:34 boston kernel: hub.c: power on to power good time: 2ms
Jan 3 08:11:34 boston kernel: hub.c: hub controller current requirement: 0mA
Jan 3 08:11:34 boston kernel: hub.c: port removable status: RR
Jan 3 08:11:34 boston kernel: hub.c: local power source is good
Jan 3 08:11:34 boston kernel: hub.c: no over-current condition exists
Jan 3 08:11:34 boston kernel: hub.c: enabling power on all ports
Jan 3 08:11:34 boston kernel: usb.c: hub driver claimed interface f6d8a3a0
Jan 3 08:11:34 boston kernel: usb.c: kusbd: /sbin/hotplug add 1
Jan 3 08:11:34 boston kernel: usb.c: kusbd policy returned 0xfffffffe
Jan 3 08:11:34 boston kernel: PCI: Setting latency timer of device 00:1d.2 to 64
Jan 3 08:11:34 boston kernel: hub.c: port 1, portstatus 100, change 0, 12 Mb/s
Jan 3 08:11:34 boston kernel: hub.c: port 2, portstatus 101, change 1, 12 Mb/s
Jan 3 08:11:34 boston kernel: hub.c: port 2 connection change
Jan 3 08:11:34 boston kernel: hub.c: port 2, portstatus 101, change 1, 12 Mb/s
Jan 3 08:11:34 boston kernel: usb.c: kmalloc IF f6d8a4c0, numif 1
Jan 3 08:11:34 boston kernel: usb.c: new device strings: Mfr=0, Product=2, SerialNumber=1
Jan 3 08:11:34 boston kernel: usb.c: USB device number 1 default language ID 0x0
Jan 3 08:11:34 boston kernel: hub.c: standalone hub
Jan 3 08:11:34 boston kernel: hub.c: ganged power switching
Jan 3 08:11:34 boston kernel: hub.c: global over-current protection
Jan 3 08:11:34 boston kernel: hub.c: Port indicators are not supported
Jan 3 08:11:34 boston kernel: hub.c: power on to power good time: 2ms
Jan 3 08:11:34 boston kernel: hub.c: hub controller current requirement: 0mA
Jan 3 08:11:34 boston kernel: hub.c: port removable status: RR
Jan 3 08:11:34 boston kernel: hub.c: local power source is good
Jan 3 08:11:34 boston kernel: hub.c: no over-current condition exists
Jan 3 08:11:34 boston kernel: hub.c: enabling power on all ports
Jan 3 08:11:34 boston kernel: usb.c: hub driver claimed interface f6d8a4c0
Jan 3 08:11:34 boston kernel: usb.c: kusbd: /sbin/hotplug add 1
Jan 3 08:11:34 boston kernel: usb.c: kusbd policy returned 0xfffffffe
Jan 3 08:11:34 boston kernel: hub.c: port 2, portstatus 101, change 0, 12 Mb/s
Jan 3 08:11:34 boston last message repeated 3 times
Jan 3 08:11:34 boston kernel: hub.c: port 2, portstatus 103, change 0, 12 Mb/s
Jan 3 08:11:34 boston kernel: usb.c: kmalloc IF f6d8a560, numif 1
Jan 3 08:11:34 boston kernel: usb.c: new device strings: Mfr=73, Product=87, SerialNumber=107
Jan 3 08:11:34 boston kernel: usb.c: USB device number 2 default language ID 0x409
Jan 3 08:11:34 boston kernel: usb-storage: act_altsettting is 0
Jan 3 08:11:34 boston kernel: usb-storage: id_index calculated to be: 86
Jan 3 08:11:34 boston kernel: usb-storage: Array length appears to be: 88
Jan 3 08:11:34 boston kernel: usb-storage: USB Mass Storage device detected
Jan 3 08:11:34 boston kernel: usb-storage: Endpoints: In: 0xf6dfd574 Out: 0xf6dfd560 Int: 0xf6dfd588 (Period 16)
Jan 3 08:11:34 boston kernel: usb-storage: New GUID 093b002011100e00004b6be4
Jan 3 08:11:34 boston kernel: usb-storage: GetMaxLUN command result is 1, data is 0
Jan 3 08:11:34 boston kernel: usb-storage: Transport: Bulk
Jan 3 08:11:34 boston kernel: usb-storage: Protocol: Transparent SCSI
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Command INQUIRY (6 bytes)
Jan 3 08:11:34 boston kernel: usb-storage: 12 00 00 00 ff 00 00 00 5a 07 00 00
Jan 3 08:11:34 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x1 Trg 0 LUN 0 L 255 F 128 CL 6
Jan 3 08:11:34 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:11:34 boston kernel: usb-storage: usb_stor_transfer_partial(): xfer 255 bytes
Jan 3 08:11:34 boston kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 96/255
Jan 3 08:11:34 boston kernel: usb-storage: Bulk data transfer result 0x1
Jan 3 08:11:34 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:11:34 boston kernel: usb-storage: clearing endpoint halt for pipe 0xc0010280
Jan 3 08:11:34 boston kernel: usb-storage: usb_stor_clear_halt: result=0
Jan 3 08:11:34 boston kernel: usb-storage: Attempting to get CSW (2nd try)...
Jan 3 08:11:34 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:11:34 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x1 R 159 Stat 0x0
Jan 3 08:11:34 boston kernel: usb-storage: Fixing INQUIRY data to show SCSI rev 2 - was 0
Jan 3 08:11:34 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad LUN (0/1)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad target number (1/0)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad target number (2/0)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad target number (3/0)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad target number (4/0)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad target number (5/0)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad target number (6/0)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: usb-storage: queuecommand() called
Jan 3 08:11:34 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:11:34 boston kernel: usb-storage: Bad target number (7/0)
Jan 3 08:11:34 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:11:34 boston kernel: WARNING: USB Mass Storage data integrity not assured
Jan 3 08:11:34 boston kernel: USB Mass Storage device found at 2
Jan 3 08:11:34 boston kernel: usb.c: usb-storage driver claimed interface f6d8a560
Jan 3 08:11:34 boston kernel: usb.c: kusbd: /sbin/hotplug add 2
Jan 3 08:11:34 boston kernel: usb.c: kusbd policy returned 0xfffffffe
Jan 3 08:11:34 boston kernel: hub.c: port 1, portstatus 100, change 0, 12 Mb/s
Jan 3 08:11:34 boston kernel: hub.c: port 2, portstatus 103, change 0, 12 Mb/s


********* issuing "tstdvd" ...
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command MODE_SENSE (6 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 1a 00 2a 00 80 00 5d f9 41 54 62 f9
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x2 Trg 0 LUN 0 L 128 F 128 CL 6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): xfer 128 bytes
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 0/128
Jan 3 08:17:48 boston kernel: usb-storage: Bulk data transfer result 0x1
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: clearing endpoint halt for pipe 0xc0010280
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_clear_halt: result=0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW (2nd try)...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x2 R 128 Stat 0x1
Jan 3 08:17:48 boston kernel: usb-storage: -- transport indicates command failure
Jan 3 08:17:48 boston kernel: usb-storage: Issuing auto-REQUEST_SENSE
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x3 Trg 0 LUN 0 L 18 F 128 CL 6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): xfer 18 bytes
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 18/18
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jan 3 08:17:48 boston kernel: usb-storage: Bulk data transfer result 0x0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x3 R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: -- Result from auto-sense is 0
Jan 3 08:17:48 boston kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x20, ASCQ: 0x0
Jan 3 08:17:48 boston kernel: usb-storage: Illegal Request: invalid command operation code
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x2
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command TEST_UNIT_READY (6 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 00 00 00 00 00 00 00 00 d3 87 10 c0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x4 Trg 0 LUN 0 L 0 F 0 CL 6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x4 R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command READ_TOC (10 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 43 00 00 00 00 00 00 00 0c 40 00 00
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x5 Trg 0 LUN 0 L 12 F 128 CL 10
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): xfer 12 bytes
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 12/12
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jan 3 08:17:48 boston kernel: usb-storage: Bulk data transfer result 0x0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x5 R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command READ_TOC (10 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 43 00 00 00 00 00 00 00 0c 00 8e f6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x6 Trg 0 LUN 0 L 12 F 128 CL 10
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): xfer 12 bytes
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 12/12
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jan 3 08:17:48 boston kernel: usb-storage: Bulk data transfer result 0x0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x6 R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command READ_TOC (10 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 43 00 00 00 00 00 01 00 0c 00 8e f6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x7 Trg 0 LUN 0 L 12 F 128 CL 10
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): xfer 12 bytes
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 12/12
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jan 3 08:17:48 boston kernel: usb-storage: Bulk data transfer result 0x0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x7 R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command READ_CAPACITY (10 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 25 00 00 00 00 00 00 00 00 00 bd f6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x8 Trg 0 LUN 0 L 8 F 128 CL 10
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): xfer 8 bytes
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_bulk_msg() returned 0 xferred 8/8
Jan 3 08:17:48 boston kernel: usb-storage: usb_stor_transfer_partial(): transfer complete
Jan 3 08:17:48 boston kernel: usb-storage: Bulk data transfer result 0x0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x8 R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command TEST_UNIT_READY (6 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 00 00 00 00 00 00 2c c0 00 d0 2c c0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0x9 Trg 0 LUN 0 L 0 F 0 CL 6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0x9 R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.
Jan 3 08:17:48 boston kernel: usb-storage: queuecommand() called
Jan 3 08:17:48 boston kernel: usb-storage: *** thread awakened.
Jan 3 08:17:48 boston kernel: usb-storage: Command ALLOW_MEDIUM_REMOVAL (6 bytes)
Jan 3 08:17:48 boston kernel: usb-storage: 1e 00 00 00 00 00 8e f6 00 00 00 00
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command S 0x43425355 T 0xa Trg 0 LUN 0 L 0 F 0 CL 6
Jan 3 08:17:48 boston kernel: usb-storage: Bulk command transfer result=0
Jan 3 08:17:48 boston kernel: usb-storage: Attempting to get CSW...
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status result = 0
Jan 3 08:17:48 boston kernel: usb-storage: Bulk status Sig 0x53425355 T 0xa R 0 Stat 0x0
Jan 3 08:17:48 boston kernel: usb-storage: scsi cmd done, result=0x0
Jan 3 08:17:48 boston kernel: usb-storage: *** thread sleeping.

2004-01-03 01:09:18

by Jeff Chua

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication

On Sat, 3 Jan 2004, Jeff Chua wrote:

> The log showed "Illegal Request: invalid command operation code" when I
> issued "tstdvd".

> Jan 3 08:17:48 boston kernel: usb-storage: -- code: 0x70, key: 0x5, ASC: 0x20, ASCQ: 0x0
> Jan 3 08:17:48 boston kernel: usb-storage: Illegal Request: invalid command operation code


Ok, I applied Jens's patch, rmmod sg, rmmod cdrom, and retest "tstdvd".

This time, debug still shows the same "Illegal Request", BUT the drive
successfully authenticated.

I tried the following command, but still couldn't get scsi log ...

echo "scsi log error,scan,mlqueue,mlcomplete,llqueue,llcomplete,hlqueue,hlcomplete 9"
>/proc/scsi/scsi


Thanks,
Jeff


2004-01-03 02:02:09

by Jeff Chua

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication


> BTW Jeff, I'd still very much like to see the usb-storage log from when
> sr gets loaded. Even though it's fine to kill the CDC_DVD checks, it
> would still be a good idea to fix why the capabilities check fails. That
> is the real bug.

Jens,

How else can I help to pin-point the source of this problem?

tstdvd can authenticate the drive now.

Thank again for your help.


Jeff.

2004-01-03 01:58:51

by Jeff Chua

[permalink] [raw]
Subject: Re: GetASF failed on DVD authentication


On Fri, 2 Jan 2004, Michael Hunold wrote:

> > scsi0 : SCSI emulation for USB Mass Storage devices
> > Vendor: PIONEER Model: DVD-RW DVR-K11 Rev: 1.00
> > Type: CD-ROM ANSI SCSI revision: 02
> > Attached scsi CD-ROM sr0 at scsi0, channel 0, id 0, lun 0
> > sr0: scsi-1 drive

Michael,

Thanks for the pointer and the patch. Now I can successfully use mplayer
on my usb drive. I decided to use Jens' patch as it's simpler.

Thanks,
Jeff.