Bug 1822 - usb-storage borks out with my camera
Summary: usb-storage borks out with my camera
Status: CLOSED CODE_FIX
Alias: None
Product: IO/Storage
Classification: Unclassified
Component: SCSI (show other bugs)
Hardware: i386 Linux
: P2 high
Assignee: Matthew Dharm
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2004-01-09 09:01 UTC by Andr
Modified: 2004-03-13 03:20 UTC (History)
5 users (show)

See Also:
Kernel Version: 2.6.1
Subsystem:
Regression: ---
Bisected commit-id:


Attachments
usb-storage debug (2.20 KB, text/plain)
2004-02-06 08:47 UTC, Andr
Details
.config file (26.60 KB, text/plain)
2004-02-06 13:38 UTC, Andr
Details
debug with the right kernel modules (or so I hope) (83.09 KB, text/plain)
2004-02-06 14:04 UTC, Andr
Details
diff between working and non-working unusual_devs.h (1.74 KB, text/plain)
2004-02-06 14:42 UTC, Andr
Details
diff -u (3.37 KB, text/plain)
2004-02-06 16:04 UTC, Andr
Details
/proc/bus/usb/devices (2.58 KB, text/plain)
2004-02-06 16:05 UTC, Andr
Details
Test patch (504 bytes, patch)
2004-02-16 01:12 UTC, Matthew Dharm
Details | Diff
kernel log (195.95 KB, text/plain)
2004-02-16 10:41 UTC, Andr
Details
kernel log-2 (15.26 KB, text/plain)
2004-02-16 14:50 UTC, Andr
Details
kernel log-3 (124.38 KB, text/plain)
2004-02-16 16:00 UTC, Andr
Details
kernel log-4 (203.08 KB, text/plain)
2004-03-12 13:40 UTC, Andr
Details

Description Andr 2004-01-09 09:01:27 UTC
I get this, while plugin my FinePix2400Zom camera to me USB port (it does work
with the 2.4 kernel series):

Initializing USB Mass Storage driver...
scsi0 : SCSI emulation for USB Mass Storage devices
  Vendor: Fujifilm  Model: FinePix 1400Zoom  Rev: 1000
  Type:   Direct-Access                      ANSI SCSI revision: 02
sda : READ CAPACITY failed.
sda : status=0, message=00, host=7, driver=00
sda : sense not available.
sda: assuming Write Enabled
sda: assuming drive cache: write through
sda : READ CAPACITY failed.
sda : status=0, message=00, host=7, driver=00
sda : sense not available.
sda: assuming Write Enabled
sda: assuming drive cache: write through
sda : READ CAPACITY failed.
sda : status=0, message=00, host=7, driver=00
sda : sense not available.
sda: assuming Write Enabled
sda: assuming drive cache: write through
 /dev/scsi/host0/bus0/target0/lun0:<3>Buffer I/O error on device sda, logical
block 0
Buffer I/O error on device sda, logical block 0
 unable to read partition table
 /dev/scsi/host0/bus0/target0/lun0:<3>Buffer I/O error on device sda, logical
block 0
 unable to read partition table
Attached scsi removable disk sda at scsi0, channel 0, id 0, lun 0
Attached scsi generic sg0 at scsi0, channel 0, id 0, lun 0,  type 0
WARNING: USB Mass Storage data integrity not assured
USB Mass Storage device found at 3
drivers/usb/core/usb.c: registered new driver usb-storage
USB Mass Storage support registered.
usbfs: USBDEVFS_CONTROL failed cmd usbmodules dev 3 rqt 128 rq 6 len 18 ret -110



^^^^^^^^^ lots of those like this last line.
Comment 1 Steven Walter 2004-01-20 17:52:02 UTC
I've got a confirmation on that.  It's a Creative Muvo USB mass storage device
for me.  Works under kernel 2.4.22, however on 2.6.1 it doesn't find the
partition sda1, and any accesses to /dev/sda or /proc/scsi/scsi after insertion
of the device stall in disk-wait indefinitely.

One difference is that with my device, the I/O error occurs on the very last
sector.  An off-by-one bug perhaps?
Comment 2 Matthew MacLeod 2004-01-25 14:10:11 UTC
I can confirm the same problem with my Muvo on 2.6.x Kernels, up to and
including 2.6.1. This is on Mandrake. Usbview shows it as an "unknown device."
My dmesg output is as follows:

hub 1-0:1.0: new USB device on port 3, assigned address 5
Initializing USB Mass Storage driver...
scsi1 : SCSI emulation for USB Mass Storage devices
  Vendor: CREATIVE  Model: NOMAD_MUVO        Rev: 0001
  Type:   Direct-Access                      ANSI SCSI revision: 02
SCSI device sda: 256001 512-byte hdwr sectors (131 MB)
sda: assuming Write Enabled
sda: assuming drive cache: write through
 /dev/scsi/host1/bus0/target0/lun0:end_request: I/O error, dev sda, sector 256000
Buffer I/O error on device sda, logical block 256000
Comment 3 Andr 2004-02-05 16:30:34 UTC
I have the same problem with  Fujifilm 2400Zoom, and now with the kernel 2.6.2
Comment 4 Matthew Dharm 2004-02-05 16:38:13 UTC
It would be very helpful to turn on USB Mass Storage Verbose Debug (kernel
config option) and post the logs.
Comment 5 Andr 2004-02-06 08:47:07 UTC
Created attachment 2033 [details]
usb-storage debug

dmesg log with usb-storage debuging turned on
Comment 6 Matthew Dharm 2004-02-06 13:02:21 UTC
The log you provided doesn't show any errors.  In fact, it doesn't show any
requests to read MODE_SENSE data or READ_CAPACITY, as your earlier dmesg output
suggests.

It seems that you either cut the log off too soon, or didn't follow the same
test procedure to reproduce the problem.
Comment 7 Andr 2004-02-06 13:37:31 UTC
Actually I've changed the kernel config file a bit when I turned the VERBOSE on.
I'll attach my current .config and try my previous config later.
Comment 8 Andr 2004-02-06 13:38:36 UTC
Created attachment 2034 [details]
.config file
Comment 9 Andr 2004-02-06 14:04:18 UTC
Created attachment 2035 [details]
debug with the right kernel modules (or so I hope)

apparently some options on the kernel refering to SCSI were missing, perhaps
they should be made mandatory if usb storage gets selected? Either way, the
attachement has the kernel log of the usb-storage with the kernel 2.6.2-rc3.
Comment 10 Matthew Dharm 2004-02-06 14:19:51 UTC
If this log is correct, the communication with the camera goes out to lunch
almost instantly.

You say this worked with 2.4?  Could you find a 2.4 kernel that it works with
and provide the diff between the drivers/usb/storage/unusual_devs.h file from
that kernel and the 2.6 you're working with now?
Comment 11 Andr 2004-02-06 14:42:52 UTC
Created attachment 2036 [details]
diff between working and non-working unusual_devs.h

diff linux-2.6.0/drivers/usb/storage/unusual_devs.h
linux-2.4.22/drivers/usb/storage/unusual_devs.h > diff-2.6.0|2.4.22
Comment 12 Matthew Dharm 2004-02-06 15:05:20 UTC
That should be a diff -u, please.

I'll also need the contents of /proc/bus/usb/devices when the unit is attached.
Comment 13 Andr 2004-02-06 16:04:21 UTC
Created attachment 2037 [details]
diff -u
Comment 14 Andr 2004-02-06 16:05:50 UTC
Created attachment 2038 [details]
/proc/bus/usb/devices
Comment 15 Matthew Dharm 2004-02-14 18:06:34 UTC
Alright, I see what's wrong here.  I'll cook up a patch to try soon (my day 
job is consuming most of my time now).
Comment 16 Andr 2004-02-14 18:40:36 UTC
thanks :)
Comment 17 Matthew Dharm 2004-02-16 01:12:02 UTC
Created attachment 2143 [details]
Test patch

Try this patch.  This isn't final, but it should be informative.
Comment 18 Andr 2004-02-16 10:41:59 UTC
Created attachment 2151 [details]
kernel log

this is the kernel log I get with the kernel 2.6.2 with the Test Patch applied.
Comment 19 Matthew Dharm 2004-02-16 14:16:31 UTC
This is better, oddly enough.  We're definately getting much futher in 
communicating with the camera.

At this point, I think we need to reduce the max_sectors to something much 
smaller than the default of 128.  You can either do that by tweaking the 
max_sectors parameter in sysfs (if you know how to do that -- it's a parameter 
of the usb-storage virtual SCSI host), or by changing the parameter directly 
in linux/drivers/usb/storage/scsiglue.c

The file may be easier for you to change.  Look for the text 'max_sectors' and 
reduce the value to something like 8 or 16 -- that's overly cautious in terms 
of size, but it should give us the data we need.
Comment 20 Andr 2004-02-16 14:25:48 UTC
I only have this:

        /* limit the total size of a transfer to 120 KB */
        .max_sectors =                  240,

should I change the 240 to 8 or 16?
Comment 21 Matthew Dharm 2004-02-16 14:26:33 UTC
Either 8 or 16 will be sufficient for this test.  Use 8.
Comment 22 Andr 2004-02-16 14:50:56 UTC
Created attachment 2154 [details]
kernel log-2

max-sectors = 8
Comment 23 Matthew Dharm 2004-02-16 15:17:08 UTC
Uhh... you didn't actually try to access the disk in that logfile.
Comment 24 Andr 2004-02-16 15:31:18 UTC
that's because I can't....

sda1 showed, but desapeared right away and now I don't see any way to access to
the device (sda?)
Comment 25 Matthew Dharm 2004-02-16 15:40:39 UTC
sda disappeared?!!?

Are you certain?  That's a behavior that makes no sense at all, unless you 
unplugged the device -- something that the log file distinctly does not show.

I suggest you reboot and repeat the test.
Comment 26 Andr 2004-02-16 15:44:20 UTC
yes, I am certain...

right after the reboot I did tried to mount the device, but the mount process
hanged.

now after I've tried again, sda1 was there, but then desapeared and only sda was
there, and yes, the camera was still plugged.

I'll do a reboot in a few moments and try the mount again and post the log.
Comment 27 Andr 2004-02-16 15:56:33 UTC
amazing!

it started working now out of the blue!

<-SNIP->
lapy esgrovas # mount /dev/sda1 /mnt/cam -t vfat
lapy esgrovas # ls /mnt/cam/
dcim
<-SNIP->


one odd thing though. The led on the cam that shows that transfers are beeing
made is always ON, usually it only turns on on _filesystem_ operations on the cam.


I'll attach the kernel log, just gimme a minute
Comment 28 Andr 2004-02-16 16:00:34 UTC
Created attachment 2155 [details]
kernel log-3

dmesg on a _working_ kernel
Comment 29 Matthew Dharm 2004-02-16 16:11:31 UTC
I like to think that it's less "out of the blue" and more "due to my 
efforts". :)

Good news: it works.
Bad news: you're not done yet.

I need you to try various max_sector sizes until you find where it breaks.  
Make sure you test each setting extensively -- lots of reads of files and 
directories.

You might want to figure out how to do this via sysfs, since then you won't 
have to recompile every time.  But if you don't want to do that, then 
recompiling is just fine as far as I'm concerned.

Once we have a good value for max_sectors, I'll cook up a final patch.
Comment 30 Andr 2004-02-16 16:13:59 UTC
eheh

sorry for that :)

if course it was due to your work :)

I'll try higer values and post back where it breaks, just gimme a day
Comment 31 Andr 2004-02-19 16:31:12 UTC
100 doesn't cut it, that's for sure...

lapy 100_fuji # ls
dscf0098.jpg  dscf0099.jpg  dscf0100.jpg
lapy 100_fuji # cp * /home/esgrovas/
cp: reading `dscf0098.jpg': Input/output error
cp: cannot stat `dscf0099.jpg': No such file or directory
cp: cannot stat `dscf0100.jpg': No such file or directory
lapy 100_fuji # ls
lapy 100_fuji # ls


going to keep on lowering the values (this is with 2.6.3 btw)
Comment 32 Andr 2004-02-19 16:32:43 UTC
btw, lots of:

scsi0 (0:0): rejecting I/O to dead device
FAT: Directory bread(block 73) failed

on dmesg
Comment 33 Christian Kaltepoth 2004-02-19 23:44:15 UTC
I'm also using a FinePix2400Zoom Cam and got the same problem as Andr
Comment 34 Andr 2004-02-20 17:56:34 UTC
I've found my magical max_sectors, I can do transfers and work with the cam
without trashing with max_sectors = 30.
Comment 35 Andr 2004-03-12 13:35:22 UTC
kernel 2.6.4, and still no go :-(

wasn't it supposed to be fixed on this version?


thanks
Comment 36 Andr 2004-03-12 13:40:41 UTC
Created attachment 2322 [details]
kernel log-4

kernel 2.6.4 with mass storage verbose
Comment 37 Matthew Dharm 2004-03-12 17:34:00 UTC
The original bug reported was fixed.  Many people report that the fix works for
them.  Something else has broken on your system -- your HCD is reporting -110,
which shouldn't be happening given that (a) the URB has no timeout, and (b) a
manual unlink was not called for.

I suggest opening a new bug for this.
Comment 38 Andr 2004-03-13 03:20:17 UTC
http://bugzilla.kernel.org/show_bug.cgi?id=2292

new bug report

Note You need to log in before you can comment on or make changes to this bug.