GetASF failed on DVD authentication

GetASF failed on DVD authentication

[Jeff Chua]

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.

Re: GetASF failed on DVD authentication

[Jens Axboe]

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

Re: GetASF failed on DVD authentication

[Jeff Chua]

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

Re: GetASF failed on DVD authentication

[Jens Axboe]

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

Re: GetASF failed on DVD authentication

[Michael Hunold]

[-- Attachment #1: Type: text/plain, Size: 2299 bytes --]

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.

[-- Attachment #2: usb-scsi-2-dvd.patch --]
[-- Type: text/plain, Size: 606 bytes --]

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);

Re: GetASF failed on DVD authentication

[Jens Axboe]

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

Re: GetASF failed on DVD authentication

[Jens Axboe]

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

Re: GetASF failed on DVD authentication

[Jeff Chua]

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.

Re: GetASF failed on DVD authentication

[Jeff Chua]

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

Re: GetASF failed on DVD authentication

[Jeff Chua]

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.

Re: GetASF failed on DVD authentication

[Jeff Chua]

> 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.