Numerous problems, partial success getting FujiFilm Finepix 3800 to work under 2.6.

DISCUSSION Alan Stern 4 participants 7 messages Apr 20, 2004 – Apr 22, 2004 1 message not in the archive SCSI

lore

Share & tools

lore

A message that is not in the archive (sent off-list or not yet received): [email protected]

Alan Stern

author

2004-04-20 19:41 UTC #1 lore raw

Quoted 9 lines · Aleksey Nogin

I am having trouble getting my FujiFilm Finepix 3800 camera to work with the 2.6.5 kernel (under Fedora Core Development - AKA Red Hat Raw Hide). It worked fine under 2.4 (both in Fedora Core 1 and Red Hat Linux 9, I believe).
After a lot of messing up and some blind experimentations with unusual_devs.h I have been successful in making camera work, but _only_ when it is connected directly to the computer, not via a hub with other devices attached.

That doesn't make much sense. Your original setup, with no unusual_devs.h entry, should have worked the same regardless of whether there was an external hub.

Quoted 71 lines

My setup (which used to work under 2.4) is a follows: I have an external hub connected to my laptop and I have a mouse, a printer and the camera is question connected to the hub.
I have tried the following:
------------ Attempt (0) --------------
Using it w/o any changes to the kernel - both via hub and connecting directly. It did not work:
usb 1-1: new full speed USB device using address 8 SCSI subsystem initialized
Initializing USB Mass Storage driver...
scsi0 : SCSI emulation for USB Mass Storage devices USB Mass Storage device found at 8 drivers/usb/core/usb.c: registered new driver usb-storage USB Mass Storage support registered.
and the usb_storage and scsi_mod modules get loaded. However, the camera does not seem to get "attached" to any specific /dev/xyz (or /udev/xyz for that matter) - e.g. when I try to access /dev/sda, I get "No such device or address".
------------- Attempt (1) ------------------
Next I have compiled the kernel with CONFIG_USB_STORAGE_DEBUG enabled. Now when I plugged the camera I saw the following:
usb 1-1.3: new full speed USB device using address 5 Initializing USB Mass Storage driver...
usb-storage: USB Mass Storage device detected
usb-storage: altsetting is 0, id_index is 112
usb-storage: -- associate_dev
usb-storage: Transport: Control/Bulk/Interrupt
usb-storage: Protocol: 8070i
usb-storage: Endpoints: In: 0xdfc3c2c0 Out: 0xdfc3c2d4 Int: 0xdfc3c2e8 (Period 1)
usb-storage: *** thread sleeping.
scsi0 : SCSI emulation for USB Mass Storage devices
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command INQUIRY (6 bytes)
usb-storage: 12 00 00 00 24 00
usb-storage: usb_stor_ctrl_transfer: rq=00 rqtype=21 value=0000 index=00 len=12
usb-storage: Status code 0; transferred 12/12
usb-storage: -- transfer complete
usb-storage: Call to usb_stor_ctrl_transfer() returned 0
usb-storage: usb_stor_bulk_transfer_buf: xfer 36 bytes
usb-storage: Status code 0; transferred 36/36
usb-storage: -- transfer complete
usb-storage: CBI data stage result is 0x0
usb-storage: usb_stor_intr_transfer: xfer 2 bytes
usb-storage: Status code 0; transferred 2/2
usb-storage: -- transfer complete
usb-storage: Got interrupt data (0x29, 0x0)
usb-storage: CBI IRQ data showed reserved bType 0x29
usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=81 len=0
usb-storage: usb_stor_clear_halt: result = 0
usb-storage: -- transport indicates command failure
usb-storage: Issuing auto-REQUEST_SENSE
usb-storage: usb_stor_ctrl_transfer: rq=00 rqtype=21 value=0000 index=00 len=12
usb-storage: Status code 0; transferred 12/12
usb-storage: -- transfer complete
usb-storage: Call to usb_stor_ctrl_transfer() returned 0
usb-storage: usb_stor_bulk_transfer_buf: xfer 18 bytes
usb-storage: Status code 0; transferred 18/18
usb-storage: -- transfer complete
usb-storage: CBI data stage result is 0x0
usb-storage: usb_stor_intr_transfer: xfer 2 bytes

Quoted 8 lines

usb-storage: Status code 0; transferred 2/2
usb-storage: -- transfer complete
usb-storage: Got interrupt data (0x0, 0x0)
usb-storage: -- Result from auto-sense is 0
usb-storage: -- code: 0x70, key: 0x6, ASC: 0x29, ASCQ: 0x0
usb-storage: Unit Attention: Power on, reset, or bus device reset occurred
usb-storage: scsi cmd done, result=0x2
usb-storage: *** thread sleeping.

That much is fairly normal. Your camera should not have replied with Unit Attention status to the INQUIRY command, but it's a fairly common mistake. The SCSI core wasn't expecting it, though, and as a result believed your camera was an invalid device. That's why you couldn't use it.

Quoted 5 lines

usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (1:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.

As you can see, instead of repeating the INQUIRY command the SCSI driver moved on to the next target.

This patch may improve things. Try it, with nothing added to unusual_devs.h, and see if it works even with an external hub.

Alan Stern

===== scsi_scan.c 1.57 vs edited =====

drivers/scsi/scsi_scan.c +4 -2

@@ -355,10 +355,12 @@
 	if (sreq->sr_result) {
 		if ((driver_byte(sreq->sr_result) & DRIVER_SENSE) != 0 &&
 		    (sreq->sr_sense_buffer[2] & 0xf) == UNIT_ATTENTION &&
-		    sreq->sr_sense_buffer[12] == 0x28 &&
+		    (sreq->sr_sense_buffer[12] == 0x28 ||
+		     sreq->sr_sense_buffer[12] == 0x29) &&
 		    sreq->sr_sense_buffer[13] == 0) {
-			/* not-ready to ready transition - good */
+			/* not-ready to ready transition or power-on - good */
 			/* dpg: bogus? INQUIRY never returns UNIT_ATTENTION */
+			/* Supposedly, but many buggy devices do so anyway */
 		} else
 			/*
 			 * assume no peripheral if any other sort of error

-------------------------------------------------------
This SF.Net email is sponsored by: IBM Linux Tutorials Free Linux tutorial presented by Daniel Robbins, President and CEO of GenToo technologies. Learn everything from fundamentals to system administration.http://ads.osdn.com/?ad_id=1470&alloc_id=3638&op=click
_______________________________________________
[email protected]
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel

Pete Zaitcev

2004-04-20 20:11 UTC #2 lore raw

Quoted 10 lines · On Tue, 20 Apr 2004 15:41:07 -0400 (EDT) Alan Stern…

Quoted 4 lines · Aleksey Nogin
After a lot of messing up and some blind experimentations with unusual_devs.h I have been successful in making camera work, but _only_ when it is connected directly to the computer, not via a hub with other devices attached.
That doesn't make much sense. Your original setup, with no unusual_devs.h entry, should have worked the same regardless of whether there was an external hub.

Actually it might make some sense. In 2.4 we had a problem recently where the interrupt pipe running to the external hub was not activated. Without it, hub's brain melts down.

This case is likely to be a different story, because the camera reported the unit attention and it would not be able to do it if the hub went down, but the point is it's nothing out of ordinary for devices to fail when hooked to a hub.

-- Pete

Aleksey Nogin

2004-04-21 05:01 UTC #3 lore raw

In reply to Alan Stern

Thanks a lot for your feedback. Unfortunately, your patch does not seem to affect anything.

To find out what exactly happens around the code you suggested patching, I added couple more SCSI_LOG_SCAN_BUS statements (marked "an1" and "an2" below) and turned on the SCSI_LOG_SCAN_BUS reporting.

The relevant part of scsi_scan.c now looks as follows:

...
SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: 1st INQUIRY %s
with"

         " code 0x%x\n", sreq->sr_result ?
         "failed" : "successful", sreq->sr_result));

SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan (an1): 0x%x 0x%x
0x%x 0x%x\n", driver_byte(sreq->sr_result), sreq->sr_sense_buffer[2], sreq->sr_sense_buffer[12], sreq->sr_sense_buffer[13]));

   if (sreq->sr_result) {
      if ((driver_byte(sreq->sr_result) & DRIVER_SENSE) != 0 &&
          (sreq->sr_sense_buffer[2] & 0xf) == UNIT_ATTENTION &&
          (sreq->sr_sense_buffer[12] == 0x28 ||
                     sreq->sr_sense_buffer[12] == 0x29) &&
          sreq->sr_sense_buffer[13] == 0) {
         /* not-ready to ready transition or power-on - good */
         /* dpg: bogus? INQUIRY never returns UNIT_ATTENTION */
         /* Supposedly, but many buggy devices do so anyway  */
      } else
         /*
          * assume no peripheral if any other sort of error
          */
         return;
   }

/*
* Get any flags for this device.
*
* XXX add a bflags to Scsi_Device, and replace the corresponding
* bit fields in Scsi_Device, so bflags need not be passed as an
* argument.
*/
*bflags |= scsi_get_device_flags(sdev, &inq_result[8], &inq_result[16]);

   possible_inq_resp_len = (unsigned char) inq_result[4] + 5;

SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan (an2): %i 0x%x\n",
possible_inq_resp_len, *bflags));;

if (BLIST_INQUIRY_36 & *bflags)
...

In the logs I now se

Initializing USB Mass Storage driver...
usb-storage: USB Mass Storage device detected
usb-storage: altsetting is 0, id_index is 112
usb-storage: -- associate_dev
usb-storage: Transport: Control/Bulk/Interrupt
usb-storage: Protocol: 8070i
usb-storage: Endpoints: In: 0x1c39d2f8 Out: 0x1c39d30c Int: 0x1c39d320 (Period 1)
usb-storage: *** thread sleeping.
Wake up parent of scsi_eh_0
Error handler scsi_eh_0 sleeping
scsi0 : SCSI emulation for USB Mass Storage devices
scsi_scan_host_selected: <0:4294967295:4294967295:4294967295>
scsi scan: INQUIRY to host 0 channel 0 id 0 lun 0
scsi_add_timer: scmd: 0372bc24, time: 6000, (22a9e255)
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Command INQUIRY (6 bytes)
usb-storage: 12 00 00 00 24 00
usb-storage: usb_stor_ctrl_transfer: rq=00 rqtype=21 value=0000 index=00 len=12
usb-storage: Status code 0; transferred 12/12
usb-storage: -- transfer complete
usb-storage: Call to usb_stor_ctrl_transfer() returned 0
usb-storage: usb_stor_bulk_transfer_buf: xfer 36 bytes
usb-storage: Status code 0; transferred 36/36
usb-storage: -- transfer complete
usb-storage: CBI data stage result is 0x0
usb-storage: usb_stor_intr_transfer: xfer 2 bytes
usb-storage: Status code 0; transferred 2/2
usb-storage: -- transfer complete
usb-storage: Got interrupt data (0x29, 0x0)
usb-storage: CBI IRQ data showed reserved bType 0x29
usb-storage: usb_stor_control_msg: rq=01 rqtype=02 value=0000 index=81 len=0
usb-storage: usb_stor_clear_halt: result = 0
usb-storage: -- transport indicates command failure
usb-storage: Issuing auto-REQUEST_SENSE
usb-storage: usb_stor_ctrl_transfer: rq=00 rqtype=21 value=0000 index=00 len=12
usb-storage: Status code 0; transferred 12/12
usb-storage: -- transfer complete
usb-storage: Call to usb_stor_ctrl_transfer() returned 0
usb-storage: usb_stor_bulk_transfer_buf: xfer 18 bytes
usb-storage: Status code 0; transferred 18/18
usb-storage: -- transfer complete
usb-storage: CBI data stage result is 0x0
usb-storage: usb_stor_intr_transfer: xfer 2 bytes
usb-storage: Status code 0; transferred 2/2
usb-storage: -- transfer complete
usb-storage: Got interrupt data (0x0, 0x0)
usb-storage: -- Result from auto-sense is 0
usb-storage: -- code: 0x70, key: 0x6, ASC: 0x29, ASCQ: 0x0
usb-storage: Unit Attention: Power on, reset, or bus device reset occurred
usb-storage: scsi cmd done, result=0x2
scsi_delete_timer: scmd: 0372bc24, rtn: 1
usb-storage: *** thread sleeping.
scsi scan: 1st INQUIRY failed with code 0x8000002
scsi scan (an1): 0x8 0x6 0x29 0x0
scsi scan (an2): 36 0xe000
scsi scan: INQUIRY to host 0 channel 0 id 1 lun 0
scsi_add_timer: scmd: 0372bc24, time: 6000, (22a9e255)
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (1:0)
...

Quoted 38 lines · Alan Stern

That much is fairly normal. Your camera should not have replied with Unit Attention status to the INQUIRY command, but it's a fairly common mistake. The SCSI core wasn't expecting it, though, and as a result believed your camera was an invalid device. That's why you couldn't use it.
Quoted 5 lines
usb-storage: queuecommand called
usb-storage: *** thread awakened.
usb-storage: Bad target number (1:0)
usb-storage: scsi cmd done, result=0x40000
usb-storage: *** thread sleeping.
As you can see, instead of repeating the INQUIRY command the SCSI driver moved on to the next target.
This patch may improve things. Try it, with nothing added to unusual_devs.h, and see if it works even with an external hub.
Alan Stern
===== scsi_scan.c 1.57 vs edited =====
drivers/scsi/scsi_scan.c +4 -2
@@ -355,10 +355,12 @@
 	if (sreq->sr_result) {
 		if ((driver_byte(sreq->sr_result) & DRIVER_SENSE) != 0 &&
 		    (sreq->sr_sense_buffer[2] & 0xf) == UNIT_ATTENTION &&
-		    sreq->sr_sense_buffer[12] == 0x28 &&
+		    (sreq->sr_sense_buffer[12] == 0x28 ||
+		     sreq->sr_sense_buffer[12] == 0x29) &&
 		    sreq->sr_sense_buffer[13] == 0) {
-			/* not-ready to ready transition - good */
+			/* not-ready to ready transition or power-on - good */
 			/* dpg: bogus? INQUIRY never returns UNIT_ATTENTION */
+			/* Supposedly, but many buggy devices do so anyway */
 		} else
 			/*
 			 * assume no peripheral if any other sort of error

Signature · 5 lines

Aleksey Nogin

Home Page: http://nogin.org/
E-Mail: [email protected] (office), [email protected] (personal)
Office: Jorgensen 70, tel: (626) 395-2907

Alan Stern

author

2004-04-21 14:43 UTC #4 lore raw

Quoted 2 lines · Aleksey Nogin

Thanks a lot for your feedback. Unfortunately, your patch does not seem to affect anything.

Yes, now you come to mention it, I see there isn't any code in there to retry the INQUIRY command after a Unit Attention! All right, try this patch instead.

Alan Stern

===== drivers/scsi/scsi_scan.c 1.57 vs edited =====

drivers/scsi/scsi_scan.c +8 -2

@@ -331,6 +331,7 @@
 	struct scsi_device *sdev = sreq->sr_device;	/* a bit ugly */
 	unsigned char scsi_cmd[MAX_COMMAND_SIZE];
 	int possible_inq_resp_len;
+	int count = 0;
 
 	*bflags = 0;
  repeat_inquiry:

@@ -351,14 +352,19 @@
 	SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: 1st INQUIRY %s with"
 			" code 0x%x\n", sreq->sr_result ?
 			"failed" : "successful", sreq->sr_result));
+	++count;
 
 	if (sreq->sr_result) {
 		if ((driver_byte(sreq->sr_result) & DRIVER_SENSE) != 0 &&
 		    (sreq->sr_sense_buffer[2] & 0xf) == UNIT_ATTENTION &&
-		    sreq->sr_sense_buffer[12] == 0x28 &&
+		    (sreq->sr_sense_buffer[12] == 0x28 ||
+		     sreq->sr_sense_buffer[12] == 0x29) &&
 		    sreq->sr_sense_buffer[13] == 0) {
-			/* not-ready to ready transition - good */
+			/* not-ready to ready transition or power-on - good */
 			/* dpg: bogus? INQUIRY never returns UNIT_ATTENTION */
+			/* Supposedly, but many buggy devices do so anyway */
+			if (count < 3)
+				goto repeat_inquiry;
 		} else
 			/*
 			 * assume no peripheral if any other sort of error

Aleksey Nogin

2004-04-21 19:54 UTC #5 lore raw

Quoted 7 lines · Alan Stern

Quoted 1 line · Aleksey Nogin
Thanks a lot for your feedback. Unfortunately, your patch does not seem to affect anything.
Yes, now you come to mention it, I see there isn't any code in there to retry the INQUIRY command after a Unit Attention! All right, try this patch instead.

This works, thanks!

However, is still only works when connected directly. If connected through a hub, when I start copying files, after transferring in the range of 100-500KB, the system thinks that the hub was disconnected, data transfer gets stuck, then it thinks that the mouse (that is attached to the hub) is disconnected, then it thinks that the mouse is back, then everything becomes stuck. If I turn the camera off at this point, it results in a kernel oops...

Apr 21 12:36:26 dell kernel: sub 1-1.3: new full speed USB device using address 5
Apr 21 12:36:27 dell kernel: Initializing USB Mass Storage driver...
Apr 21 12:36:28 dell kernel: scsi0 : SCSI emulation for USB Mass Storage devices
Apr 21 12:36:28 dell kernel:   Vendor: FUJIFILM  Model: USB-DRIVEUNIT 
  Rev: 1.00
Apr 21 12:36:28 dell kernel:   Type:   Direct-Access 
  ANSI SCSI revision: 02
Apr 21 12:36:28 dell scsi.agent[2324]: disk at /devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.3/1-1.3:1.0/host0/0:0:0:0
Apr 21 12:36:40 dell kernel: usbcore: registered new driver usb-storage
Apr 21 12:36:40 dell kernel: USB Mass Storage support registered.
Apr 21 12:36:47 dell kernel: SCSI device sda: 512000 512-byte hdwr sectors (262 MB)
Apr 21 12:36:47 dell kernel: sda: assuming Write Enabled
Apr 21 12:36:47 dell kernel: sda: assuming drive cache: write through
Apr 21 12:36:47 dell kernel:  sda:<7>usb-storage: queuecommand called
Apr 21 12:36:47 dell kernel:  sda1
Apr 21 12:36:47 dell kernel: Attached scsi removable disk sda at scsi0, channel 0, id 0, lun 0
Apr 21 12:37:07 dell last message repeated 2 times
Apr 21 12:37:07 dell kernel: SELinux: initialized (dev sda1, type msdos), uses genfs_contexts
Apr 21 12:37:08 dell kernel: usb 1-1.1: USB disconnect, address 3
Apr 21 12:37:09 dell kernel: usb 1-1.1: new low speed USB device using address 6
Apr 21 12:37:10 dell usb.agent[3503]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:10 dell input.agent[3522]: ... no modules for INPUT product
Apr 21 12:37:10 dell input.agent[3532]: ... no modules for INPUT product
Apr 21 12:37:10 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:39 dell kernel: usb 1-1.1: USB disconnect, address 6
Apr 21 12:37:39 dell kernel: usb 1-1.1: new low speed USB device using address 7
Apr 21 12:37:39 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:37:39 dell kernel: usb 1-1.1: USB disconnect, address 7
Apr 21 12:37:40 dell usb.agent[3608]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:40 dell kernel: usb 1-1.1: new low speed USB device using address 8
Apr 21 12:37:40 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:37:41 dell usb.agent[3655]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:41 dell kernel: usb 1-1.1: USB disconnect, address 8
Apr 21 12:37:41 dell kernel: usb 1-1.1: new low speed USB device using address 9
Apr 21 12:37:42 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:37:42 dell usb.agent[3704]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:42 dell kernel: usb 1-1.1: USB disconnect, address 9
Apr 21 12:37:43 dell kernel: usb 1-1.1: new low speed USB device using address 10
Apr 21 12:37:43 dell usb.agent[3753]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:44 dell input.agent[3774]: ... no modules for INPUT product
Apr 21 12:37:44 dell input.agent[3784]: ... no modules for INPUT product
Apr 21 12:37:44 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:44 dell kernel: usb 1-1.1: USB disconnect, address 10
Apr 21 12:37:44 dell kernel: usb 1-1.1: new low speed USB device using address 11
Apr 21 12:37:45 dell usb.agent[3858]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:45 dell input.agent[3879]: ... no modules for INPUT product
Apr 21 12:37:45 dell input.agent[3889]: ... no modules for INPUT product
Apr 21 12:37:45 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:45 dell kernel: usb 1-1.1: USB disconnect, address 11
Apr 21 12:37:46 dell kernel: usb 1-1.1: new low speed USB device using address 12
Apr 21 12:37:46 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:37:47 dell usb.agent[3964]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:47 dell kernel: usb 1-1.1: USB disconnect, address 12
Apr 21 12:37:47 dell kernel: usb 1-1.1: new low speed USB device using address 13
Apr 21 12:37:48 dell usb.agent[4013]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:48 dell input.agent[4041]: ... no modules for INPUT product
Apr 21 12:37:48 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:48 dell input.agent[4034]: ... no modules for INPUT product
Apr 21 12:37:48 dell kernel: usb 1-1.1: USB disconnect, address 13
Apr 21 12:37:49 dell kernel: usb 1-1.1: new low speed USB device using address 14
Apr 21 12:37:50 dell usb.agent[4118]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:50 dell input.agent[4146]: ... no modules for INPUT product
Apr 21 12:37:50 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:50 dell input.agent[4139]: ... no modules for INPUT product
Apr 21 12:37:50 dell kernel: usb 1-1.1: USB disconnect, address 14
Apr 21 12:37:50 dell kernel: usb 1-1.1: new low speed USB device using address 15
Apr 21 12:37:50 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:37:51 dell kernel: usb 1-1.1: USB disconnect, address 15
Apr 21 12:37:51 dell usb.agent[4223]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:52 dell kernel: usb 1-1.1: new low speed USB device using address 16
Apr 21 12:37:52 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:37:52 dell usb.agent[4269]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:53 dell kernel: usb 1-1.1: USB disconnect, address 16
Apr 21 12:37:53 dell kernel: usb 1-1.1: new low speed USB device using address 17
Apr 21 12:37:53 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:37:54 dell usb.agent[4322]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:54 dell kernel: usb 1-1.1: USB disconnect, address 17
Apr 21 12:37:54 dell kernel: usb 1-1.1: new low speed USB device using address 18
Apr 21 12:37:55 dell usb.agent[4369]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:55 dell input.agent[4390]: ... no modules for INPUT product
Apr 21 12:37:55 dell input.agent[4400]: ... no modules for INPUT product
Apr 21 12:37:55 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:55 dell kernel: usb 1-1.1: USB disconnect, address 18
Apr 21 12:37:56 dell kernel: usb 1-1.1: new low speed USB device using address 19
Apr 21 12:37:57 dell usb.agent[4474]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:57 dell input.agent[4495]: ... no modules for INPUT product
Apr 21 12:37:57 dell input.agent[4505]: ... no modules for INPUT product
Apr 21 12:37:57 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:57 dell kernel: usb 1-1.1: USB disconnect, address 19
Apr 21 12:37:57 dell kernel: usb 1-1.1: new low speed USB device using address 20
Apr 21 12:37:58 dell usb.agent[4579]: ... no modules for USB product 46d/c501/910
Apr 21 12:37:58 dell input.agent[4600]: ... no modules for INPUT product
Apr 21 12:37:58 dell input.agent[4610]: ... no modules for INPUT product
Apr 21 12:37:58 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:37:59 dell kernel: usb 1-1.1: USB disconnect, address 20
Apr 21 12:37:59 dell kernel: usb 1-1.1: new low speed USB device using address 21
Apr 21 12:37:59 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:38:00 dell usb.agent[4685]: ... no modules for USB product 46d/c501/910
Apr 21 12:38:00 dell kernel: usb 1-1.1: USB disconnect, address 21
Apr 21 12:38:00 dell kernel: usb 1-1.1: new low speed USB device using address 22
Apr 21 12:38:01 dell usb.agent[4735]: ... no modules for USB product 46d/c501/910
Apr 21 12:38:01 dell input.agent[4765]: ... no modules for INPUT product
Apr 21 12:38:01 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:38:01 dell input.agent[4756]: ... no modules for INPUT product
Apr 21 12:38:01 dell kernel: usb 1-1.1: USB disconnect, address 22
Apr 21 12:38:02 dell kernel: usb 1-1.1: new low speed USB device using address 23
Apr 21 12:38:03 dell usb.agent[4841]: ... no modules for USB product 46d/c501/910
Apr 21 12:38:03 dell input.agent[4872]: ... no modules for INPUT product
Apr 21 12:38:03 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:38:03 dell input.agent[4863]: ... no modules for INPUT product
Apr 21 12:38:03 dell kernel: usb 1-1.1: USB disconnect, address 23
Apr 21 12:38:04 dell kernel: usb 1-1.1: new low speed USB device using address 24
Apr 21 12:38:04 dell kernel: hid: probe of 1-1.1:1.0 failed with error -5
Apr 21 12:38:04 dell usb.agent[4948]: ... no modules for USB product 46d/c501/910
Apr 21 12:38:04 dell kernel: usb 1-1.1: USB disconnect, address 24
Apr 21 12:38:05 dell kernel: usb 1-1.1: new low speed USB device using address 25
Apr 21 12:38:06 dell usb.agent[4997]: ... no modules for USB product 46d/c501/910
Apr 21 12:38:06 dell input.agent[5018]: ... no modules for INPUT product
Apr 21 12:38:06 dell input.agent[5028]: ... no modules for INPUT product
Apr 21 12:38:06 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:38:06 dell kernel: usb 1-1.1: USB disconnect, address 25
Apr 21 12:38:06 dell kernel: usb 1-1.1: new low speed USB device using address 26
Apr 21 12:38:07 dell usb.agent[5102]: ... no modules for USB product 46d/c501/910
Apr 21 12:38:07 dell input.agent[5123]: ... no modules for INPUT product
Apr 21 12:38:07 dell input.agent[5133]: ... no modules for INPUT product
Apr 21 12:38:07 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:38:08 dell kernel: usb 1-1.1: USB disconnect, address 26
Apr 21 12:38:08 dell kernel: usb 1-1.1: new low speed USB device using address 27
Apr 21 12:38:09 dell usb.agent[5207]: ... no modules for USB product 46d/c501/910
Apr 21 12:38:09 dell input.agent[5228]: ... no modules for INPUT product
Apr 21 12:38:09 dell input.agent[5238]: ... no modules for INPUT product
Apr 21 12:38:09 dell kernel: input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.1
Apr 21 12:38:10 dell kernel: usb 1-1: control timeout on ep0out
Apr 21 12:38:14 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:14 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:15 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:15 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:16 dell kernel: usb 1-1: control timeout on ep0out
Apr 21 12:38:19 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:19 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:21 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:21 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:22 dell kernel: usb 1-1: control timeout on ep0out
Apr 21 12:38:24 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:24 dell kernel: hub 1-1:1.0: hub_hub_status failed (err = -110)
Apr 21 12:38:24 dell kernel: hub 1-1:1.0: get_hub_status failed
Apr 21 12:38:27 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:27 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:28 dell kernel: usb 1-1: control timeout on ep0out
Apr 21 12:38:29 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:29 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:32 dell shutdown: shutting down for system reboot
Apr 21 12:38:34 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:34 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:34 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:34 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:35 dell kernel: usb 1-1: control timeout on ep0out
Apr 21 12:38:39 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:39 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:40 dell kernel: usb 1-1: control timeout on ep0in
Apr 21 12:38:40 dell kernel: hub 1-1:1.0: hub_port_status failed (err = -110)
Apr 21 12:38:40 dell kernel: hub 1-1:1.0: Cannot enable port 3.  Maybe the USB cable is bad?
Apr 21 12:38:41 dell kernel: usb 1-1: control timeout on ep0out
Apr 21 12:39:22 dell kernel: hub 1-1:1.0: cannot disable port 3 (err = -110)
Apr 21 12:39:22 dell kernel: scsi: Device offlined - not ready after error recovery: host 0 channel 0 id 0 lun 0
Apr 21 12:39:22 dell kernel: SCSI error : <0 0 0 0> return code = 0x50000
Apr 21 12:39:22 dell kernel: end_request: I/O error, dev sda, sector 512
Apr 21 12:39:22 dell kernel: Buffer I/O error on device sda1, logical block 463
Apr 21 12:39:22 dell kernel: scsi0 (0:0): rejecting I/O to offline device
Apr 21 12:39:22 dell kernel: Buffer I/O error on device sda1, logical block 464
Apr 21 12:39:22 dell kernel: Buffer I/O error on device sda1, logical block 465

Signature · 5 lines

Aleksey Nogin

Home Page: http://nogin.org/
E-Mail: [email protected] (office), [email protected] (personal)
Office: Jorgensen 70, tel: (626) 395-2907

Patrick Mansfield

2004-04-22 00:40 UTC #6 lore raw

Quoted 15 lines · Aleksey Nogin

Quoted 10 lines · Alan Stern
Quoted 2 lines · Aleksey Nogin
Thanks a lot for your feedback. Unfortunately, your patch does not seem to affect anything.
Yes, now you come to mention it, I see there isn't any code in there to retry the INQUIRY command after a Unit Attention! All right, try this patch instead.
This works, thanks!

Quoted 7 lines

However, is still only works when connected directly. If connected through a hub, when I start copying files, after transferring in the range of 100-500KB, the system thinks that the hub was disconnected, data transfer gets stuck, then it thinks that the mouse (that is attached to the hub) is disconnected, then it thinks that the mouse is back, then everything becomes stuck. If I turn the camera off at this point, it results in a kernel oops...

Where's the oops? This sounds like a badness John sent to me about a USB cdrom device that gets an error, and when it is later removed hits a WARN_ON in scsi_device_set_state.

Here's the back trace:

sr 7:0:0:0: Illegal state transition offline->cancel Badness in scsi_device_set_state at drivers/scsi/scsi_lib.c:1640

Call Trace:
 [<c02b20e5>] scsi_device_set_state+0xbe/0x10b
 [<c02ac93b>] scsi_device_cancel+0x29/0xf4
 [<c02acad5>] scsi_device_cancel_cb+0x0/0x1c
 [<c0238dd7>] device_for_each_child+0x3e/0x6e
 [<c02acb27>] scsi_host_cancel+0x36/0xab
 [<c02acad5>] scsi_device_cancel_cb+0x0/0x1c
 [<c0344af1>] usb_buffer_free+0x45/0x47
 [<c02acbb7>] scsi_remove_host+0x1b/0x5c
 [<c0360bf1>] storage_disconnect+0x39/0x49
 [<c0343b64>] usb_unbind_interface+0x7a/0x7c
 [<c0239b46>] device_release_driver+0x64/0x66
 [<c0239c6d>] bus_remove_device+0x56/0x98
 [<c0238d40>] device_del+0x5f/0x95
 [<c0238d89>] device_unregister+0x13/0x23
 [<c03495f5>] usb_disable_device+0x71/0xac
 [<c0344451>] usb_disconnect+0x9c/0xe9
 [<c0346482>] hub_port_connect_change+0x282/0x287
 [<c0345e39>] hub_port_status+0x45/0xb0
 [<c03467a9>] hub_events+0x322/0x36e
 [<c0346826>] hub_thread+0x31/0xd1
 [<c0111f86>] default_wake_function+0x0/0x12
 [<c03467f5>] hub_thread+0x0/0xd1
 [<c0102209>] kernel_thread_helper+0x5/0xb

-- Patrick Mansfield

Aleksey Nogin

2004-04-22 01:30 UTC #7 lore raw

Quoted 6 lines · Patrick Mansfield

Quoted 1 line · Aleksey Nogin
However, is still only works when connected directly. If connected through a hub, when I start copying files, after transferring in the range of 100-500KB, the system thinks that the hub was disconnected, data transfer gets stuck, then it thinks that the mouse (that is attached to the hub) is disconnected, then it thinks that the mouse is back, then everything becomes stuck. If I turn the camera off at this point, it results in a kernel oops...
Where's the oops?

Here is what I saw I time during my experimentations with unusual_devs.h:

Apr 19 23:04:21 kernel: usb 1-1.3: USB disconnect, address 9
Apr 19 23:04:29 kernel: scsi: Device offlined - not ready after error recovery: host 4 channel 0 id 0 lun 0
Apr 19 23:04:29 kernel: sd 4:0:0:0: Illegal state transition cancel->offline
Apr 19 23:04:29 kernel: Badness in scsi_device_set_state at drivers/scsi/scsi_lib.c:1640
Apr 19 23:04:29 kernel: Call Trace:
Apr 19 23:04:29 kernel:  [<e0ab6703>] scsi_device_set_state+0xb4/0xbf [scsi_mod]
Apr 19 23:04:29 kernel:  [<e0ab3ab7>] scsi_eh_offline_sdevs+0x49/0x62 [scsi_mod]
Apr 19 23:04:29 kernel:  [<e0ab419f>] scsi_unjam_host+0x24c/0x25d [scsi_mod]
Apr 19 23:04:29 kernel:  [<e0ab4406>] scsi_error_handler+0x256/0x2ad [scsi_mod]
Apr 19 23:04:29 kernel:  [<e0ab41b0>] scsi_error_handler+0x0/0x2ad [scsi_mod]
Apr 19 23:04:29 kernel:  [<c01041d9>] kernel_thread_helper+0x5/0xb

Followed by

Apr 19 23:04:47 kernel: Unable to handle kernel NULL pointer dereference at virtual address 00000110
Apr 19 23:04:47 kernel:  printing eip:
Apr 19 23:04:47 kernel: e0ab2316
Apr 19 23:04:47 kernel: *pde = 0445d067
Apr 19 23:04:47 kernel: Oops: 0000 [#1]
Apr 19 23:04:47 kernel: CPU:    0
Apr 19 23:04:47 kernel: EIP:    0060:[<e0ab2316>]    Not tainted
Apr 19 23:04:47 kernel: EFLAGS: 00210282   (2.6.5-1.327custom)
Apr 19 23:04:47 kernel: EIP is at scsi_block_when_processing_errors+0x8/0xa7 [scsi_mod]
Apr 19 23:04:47 kernel: eax: dbd05000   ebx: dbd05000   ecx: 00000000 edx: c1a5c200
Apr 19 23:04:47 kernel: esi: d0972540   edi: d80e9300   ebp: c1a5c200 esp: c40c8f04
Apr 19 23:04:47 kernel: ds: 007b   es: 007b   ss: 0068
Apr 19 23:04:47 kernel: Process umount (pid: 7116, threadinfo=c40c8000 task=c6cf1360)
Apr 19 23:04:47 kernel: Stack: 00000000 00000000 00000000 00000000 00000000 d80e9300 d80e9300 d80e9300
Apr 19 23:04:47 kernel:        dbd05000 e0e21621 00000001 d80e9300 c0167a01 d80e9368 00000000 e0e24380
Apr 19 23:04:47 kernel:        d80e9300 d80e9080 c1a5c200 c0167a9a d80e90e8 00000000 db8d7840 db8d7800
Apr 19 23:04:47 kernel: Call Trace:
Apr 19 23:04:47 kernel:  [<e0e21621>] sd_release+0x4c/0x65 [sd_mod]
Apr 19 23:04:47 kernel:  [<c0167a01>] blkdev_put+0x111/0x25a
Apr 19 23:04:47 kernel:  [<c0167a9a>] blkdev_put+0x1aa/0x25a
Apr 19 23:04:47 kernel:  [<c0163f32>] deactivate_super+0xc4/0x1e8
Apr 19 23:04:47 kernel:  [<c017fc12>] sys_umount+0x5d/0x64
Apr 19 23:04:47 kernel:  [<c0150162>] unmap_vma_list+0xe/0x17
Apr 19 23:04:47 kernel:  [<c015068a>] do_munmap+0x1dc/0x1e6
Apr 19 23:04:47 kernel:  [<c017fc24>] sys_oldumount+0xb/0xe
Apr 19 23:04:47 kernel:  [<c02e8d3b>] syscall_call+0x7/0xb
Apr 19 23:04:47 kernel:
Apr 19 23:04:47 kernel: Code: 8b 81 10 01 00 00 a8 08 74 61 b8 00 f0 ff ff 89 e2 21 e0 8b

Quoted 24 lines

This sounds like a badness John sent to me about a USB cdrom device that gets an error, and when it is later removed hits a WARN_ON in scsi_device_set_state.
Here's the back trace:
sr 7:0:0:0: Illegal state transition offline->cancel Badness in scsi_device_set_state at drivers/scsi/scsi_lib.c:1640
Call Trace:
 [<c02b20e5>] scsi_device_set_state+0xbe/0x10b
 [<c02ac93b>] scsi_device_cancel+0x29/0xf4
 [<c02acad5>] scsi_device_cancel_cb+0x0/0x1c
 [<c0238dd7>] device_for_each_child+0x3e/0x6e
 [<c02acb27>] scsi_host_cancel+0x36/0xab
 [<c02acad5>] scsi_device_cancel_cb+0x0/0x1c
 [<c0344af1>] usb_buffer_free+0x45/0x47
 [<c02acbb7>] scsi_remove_host+0x1b/0x5c
 [<c0360bf1>] storage_disconnect+0x39/0x49
 [<c0343b64>] usb_unbind_interface+0x7a/0x7c
 [<c0239b46>] device_release_driver+0x64/0x66
 [<c0239c6d>] bus_remove_device+0x56/0x98
 [<c0238d40>] device_del+0x5f/0x95
 [<c0238d89>] device_unregister+0x13/0x23
 [<c03495f5>] usb_disable_device+0x71/0xac

Quoted 8 lines

 [<c0344451>] usb_disconnect+0x9c/0xe9
 [<c0346482>] hub_port_connect_change+0x282/0x287
 [<c0345e39>] hub_port_status+0x45/0xb0
 [<c03467a9>] hub_events+0x322/0x36e
 [<c0346826>] hub_thread+0x31/0xd1
 [<c0111f86>] default_wake_function+0x0/0x12
 [<c03467f5>] hub_thread+0x0/0xd1
 [<c0102209>] kernel_thread_helper+0x5/0xb

Another time when I was testing the scsi_scan patch, I saw a one with the hub_thread in it, but the machine became completely unresponsive before I got a chance to capture it.

Signature · 5 lines

Aleksey Nogin

Home Page: http://nogin.org/
E-Mail: [email protected] (office), [email protected] (personal)
Office: Jorgensen 70, tel: (626) 395-2907