Bug 10834

Reply-To: akpm@linuxfoundation.org


(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

On Thu, 29 May 2008 16:39:25 -0700 (PDT)
bugme-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=10834
> 
>            Summary: virtual usb mass storage won`t work (g_file_storage
>                     buggy)
>            Product: Drivers
>            Version: 2.5
>      KernelVersion: 2.6.26-rc4-git2
>           Platform: All
>         OS/Version: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: normal
>           Priority: P1
>          Component: USB
>         AssignedTo: greg@kroah.com
>         ReportedBy: devzero@web.de
> 
> 
> Latest working kernel version: must be pre 2.6.20 - didn`t try for longer

Maybe it never worked.

> Earliest failing kernel version: 2.6.26-rc4-git2
> 
> Distribution: opensuse 10.1
> 
> Hardware Environment: x86 / p4 box / gigabyte mobo
> 
> Software Environment:
> 
> Problem Description:
> 
> g_file_storage has issues. found by chance when trying to test the disk image
> from http://bugzilla.kernel.org/show_bug.cgi?id=10808
> 
> [  356.980966] dummy_hcd dummy_hcd: USB Host+Gadget Emulator, driver 02 May
> 2005
> [  356.980966] dummy_hcd dummy_hcd: Dummy host controller
> [  356.980966] dummy_hcd dummy_hcd: new USB bus registered, assigned bus
> number
> 6
> [  356.980966] usb usb6: configuration #1 chosen from 1 choice
> [  356.980966] hub 6-0:1.0: USB hub found
> [  356.980966] hub 6-0:1.0: 1 port detected
> [  357.081125] usb usb6: New USB device found, idVendor=1d6b, idProduct=0002
> [  357.081125] usb usb6: New USB device strings: Mfr=3, Product=2,
> SerialNumber=1
> [  357.081125] usb usb6: Product: Dummy host controller
> [  357.081125] usb usb6: Manufacturer: Linux 2.6.26-rc4-git2 dummy_hcd
> [  357.081125] usb usb6: SerialNumber: dummy_hcd
> [  357.097125] g_file_storage gadget: File-backed Storage Gadget, version: 7
> August 2007
> [  357.097125] g_file_storage gadget: Number of LUNs=1
> [  357.097125] g_file_storage gadget-lun0: ro=0, file: /usr/src/1gig.img
> [  357.333158] usb 6-1: new high speed USB device using dummy_hcd and address
> 2
> [  357.497410] usb 6-1: configuration #1 chosen from 1 choice
> [  357.504975] g_file_storage gadget: high speed config #1
> [  357.516964] usb 6-1: New USB device found, idVendor=0525, idProduct=a4a5
> [  357.516964] usb 6-1: New USB device strings: Mfr=1, Product=2,
> SerialNumber=3
> [  357.516964] usb 6-1: Product: File-backed Storage Gadget
> [  357.516964] usb 6-1: Manufacturer: Linux 2.6.26-rc4-git2 with dummy_udc
> [  357.516964] usb 6-1: SerialNumber: 372041756775
> [  357.589267] usbcore: registered new interface driver libusual
> [  357.606688] Initializing USB Mass Storage driver...
> [  357.609677] scsi3 : SCSI emulation for USB Mass Storage devices
> [  357.610434] usbcore: registered new interface driver usb-storage
> [  357.610445] USB Mass Storage support registered.
> [  357.611449] usb-storage: device found at 2
> [  357.611458] usb-storage: waiting for device to settle before scanning
> [  362.616988] usb-storage: device scan complete
> [  362.629133] scsi 3:0:0:0: Direct-Access     Linux    File-Stor Gadget 0302
> PQ: 0 ANSI: 2
> [  362.675335] sd 3:0:0:0: [sdc] 2097152 512-byte hardware sectors (1074 MB)
> [  362.796123] sd 3:0:0:0: [sdc] Write Protect is off
> [  362.796133] sd 3:0:0:0: [sdc] Mode Sense: 0f 00 00 00
> [  362.796141] sd 3:0:0:0: [sdc] Assuming drive cache: write through
> [  362.815059] sd 3:0:0:0: [sdc] 2097152 512-byte hardware sectors (1074 MB)
> [  362.935829] sd 3:0:0:0: [sdc] Write Protect is off
> [  362.935840] sd 3:0:0:0: [sdc] Mode Sense: 0f 00 00 00
> [  362.935848] sd 3:0:0:0: [sdc] Assuming drive cache: write through
> [  362.935858]  sdc: unknown partition table
> [  362.969156] sd 3:0:0:0: [sdc] Attached SCSI disk
> [  362.969156] sd 3:0:0:0: Attached scsi generic sg3 type 0
> [  378.896392] sd 3:0:0:0: [sdc] 2097152 512-byte hardware sectors (1074 MB)
> [  379.015008] sd 3:0:0:0: [sdc] Write Protect is off
> [  379.015018] sd 3:0:0:0: [sdc] Mode Sense: 0f 00 00 00
> [  379.015049] sd 3:0:0:0: [sdc] Assuming drive cache: write through
> [  379.015059]  sdc: sdc1
> [  381.052975] sd 3:0:0:0: [sdc] 2097152 512-byte hardware sectors (1074 MB)
> [  381.172981] sd 3:0:0:0: [sdc] Write Protect is off
> [  381.172981] sd 3:0:0:0: [sdc] Mode Sense: 0f 00 00 00
> [  381.172981] sd 3:0:0:0: [sdc] Assuming drive cache: write through
> [  381.172981]  sdc: sdc1
> [  433.917140] kjournald starting.  Commit interval 5 seconds
> [  433.928980] EXT3 FS on sdc1, internal journal
> [  433.928980] EXT3-fs: mounted filesystem with ordered data mode.
> [  472.008997] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  472.161611] g_file_storage gadget: high speed config #1
> [  472.289530] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  472.441158] g_file_storage gadget: high speed config #1
> [  472.572051] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  472.721021] g_file_storage gadget: high speed config #1
> [  472.849171] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  473.001447] g_file_storage gadget: high speed config #1
> [  473.129015] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  473.285133] g_file_storage gadget: high speed config #1
> [  473.409019] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  473.563772] g_file_storage gadget: high speed config #1
> [  473.577841] sd 3:0:0:0: [sdc] Result: hostbyte=DID_ERROR
> driverbyte=DRIVER_OK,SUGGEST_OK
> [  473.577858] end_request: I/O error, dev sdc, sector 213053
> [  473.577866] Buffer I/O error on device sdc1, logical block 26624
> [  473.577871] lost page write due to I/O error on sdc1
> [  473.577883] Buffer I/O error on device sdc1, logical block 26625
> [  473.577888] lost page write due to I/O error on sdc1
> [  473.577895] Buffer I/O error on device sdc1, logical block 26626
> [  473.577900] lost page write due to I/O error on sdc1
> [  473.577907] Buffer I/O error on device sdc1, logical block 26627
> [  473.577911] lost page write due to I/O error on sdc1
> [  473.577918] Buffer I/O error on device sdc1, logical block 26628
> [  473.577923] lost page write due to I/O error on sdc1
> [  473.577930] Buffer I/O error on device sdc1, logical block 26629
> [  473.577934] lost page write due to I/O error on sdc1
> [  473.577941] Buffer I/O error on device sdc1, logical block 26630
> [  473.577946] lost page write due to I/O error on sdc1
> [  473.577952] Buffer I/O error on device sdc1, logical block 26631
> [  473.577957] lost page write due to I/O error on sdc1
> [  473.577964] Buffer I/O error on device sdc1, logical block 26632
> [  473.577969] lost page write due to I/O error on sdc1
> [  473.577976] Buffer I/O error on device sdc1, logical block 26633
> [  473.577980] lost page write due to I/O error on sdc1
> [  473.693738] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  473.845003] g_file_storage gadget: high speed config #1
> [  473.973165] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  474.129007] g_file_storage gadget: high speed config #1
> [  474.253166] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  474.407255] g_file_storage gadget: high speed config #1
> [  474.537007] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  474.685010] g_file_storage gadget: high speed config #1
> [  474.813156] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  474.965178] g_file_storage gadget: high speed config #1
> [  475.093017] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> 2
> [  475.245140] g_file_storage gadget: high speed config #1
> [  475.257030] sd 3:0:0:0: [sdc] Result: hostbyte=DID_ERROR
> driverbyte=DRIVER_OK,SUGGEST_OK
> [  475.257043] end_request: I/O error, dev sdc, sector 213157
> [  475.257140] Aborting journal on device sdc1.
> [  475.292972] __journal_remove_journal_head: freeing b_committed_data
> [  475.292972] journal commit I/O error
> 
> 
> 
> Steps to reproduce:
> 
> have kernel with the following options:
> CONFIG_USB_DUMMY_HCD=m
> CONFIG_USB_FILE_STORAGE=m
> CONFIG_USB_FILE_STORAGE_TEST=n
> 
> dd if=/dev/zero of=/usr/src/1gig.dat
> 
> modprobe g_file_storage file=/usr/src/1gig.dat
> 
> kernel recognizing new scsi device - look in dmesg for device name
> (sdb/sdc...)
> 
> then fdisk/format that device. i tried ext3.
> 
> mount somewhere
> 
> copy some data to the mount. sync

ooh, a test case. Thanks.

> besides this bug, the name "g_file_storage" sucks. isn`t that a "virtual usb
> stick/mass storage emulator" ? ;)

We're good at naming things suckily.  But alas once these things have
sucked we can no longer unsuck (blow?) them.

Reply-To: david-b@pacbell.net

> > besides this bug, the name "g_file_storage" sucks. isn`t that a "virtual
> usb
> > stick/mass storage emulator" ? ;)
>
> We're good at naming things suckily.  But alas once these things have
> sucked we can no longer unsuck (blow?) them.

I also think that

  modprobe "virtual usbstick and mass storage emulator"

syntax family would have an even harder time catching on.  It'd need
some kind of AI engine, for starters.

FWIW, "unsuck" is probably better.  "That sucks" and "that blows"
mean basically the same thing.  Isn't English wonderful?  ;)

- Dave

Reply-To: akpm@linuxfoundation.org

On Fri, 30 May 2008 02:28:11 +0200
devzero@web.de wrote:

> > > Latest working kernel version: must be pre 2.6.20 - didn`t try for longer
> > 
> > Maybe it never worked.
> 
> mhh - i think it worked - at least to some degree, see
> http://communities.vmware.com/message/521858#521858
> 
> iirc, i had done 2 things at that time:
> 
> 1. used mapped file via g_file_storage as virtual usb storage for vmware
> 2. installed a complete virtual machine to the same one  - since vmware can`t
> use arbitrary blockdevices (*sigh*) , that would be a way to trick vmware to
> use those, though - you just make a blockdevice or file somewhat look like a
> scsi disk....
> 
> cannot tell about stability, but if i had those issues i`m seeing now, i`m
> sure i would have recognized that problem earlier....
> 

Thanks, but please do resist the temptation to fiddle with the cc line.
Just do reply-to-all.

I have readded bugzilla to the cc list so the record is not broken.

On Thu, 29 May 2008, Andrew Morton wrote:

> On Thu, 29 May 2008 16:39:25 -0700 (PDT)
> bugme-daemon@bugzilla.kernel.org wrote:
> 
> > http://bugzilla.kernel.org/show_bug.cgi?id=10834

...

> > [  381.172981]  sdc: sdc1
> > [  433.917140] kjournald starting.  Commit interval 5 seconds
> > [  433.928980] EXT3 FS on sdc1, internal journal
> > [  433.928980] EXT3-fs: mounted filesystem with ordered data mode.
> > [  472.008997] usb 6-1: reset high speed USB device using dummy_hcd and
> address
> > 2

...

> > Steps to reproduce:
> > 
> > have kernel with the following options:
> > CONFIG_USB_DUMMY_HCD=m
> > CONFIG_USB_FILE_STORAGE=m
> > CONFIG_USB_FILE_STORAGE_TEST=n
> > 
> > dd if=/dev/zero of=/usr/src/1gig.dat

I presume you had a "count=" argument here and therefore didn't fill up
your entire /usr partition with 0s.

> > modprobe g_file_storage file=/usr/src/1gig.dat
> > 
> > kernel recognizing new scsi device - look in dmesg for device name
> (sdb/sdc...)
> > 
> > then fdisk/format that device. i tried ext3.
> > 
> > mount somewhere
> > 
> > copy some data to the mount. sync

We need more debugging information to find out what's wrong.  You could 
start by turning on CONFIG_USB_STORAGE_DEBUG.  Attach the dmesg log to 
the bug report.

Alan Stern

>I presume you had a "count=" argument here and therefore didn't fill up
>your entire /usr partition with 0s.
oh yes - sure. my mistake...

>We need more debugging information to find out what's wrong.  You could 
>start by turning on CONFIG_USB_STORAGE_DEBUG.  Attach the dmesg log to 
>the bug report.
ok, will report later. thanks

Created attachment 16345 [details]
dmesg log with CONFIG_USB_STORAGE_DEBUG=y

there you are.

dmesg.txt contains all events while doing :

modprobe g_file_storage file=/usr/src/1gig.img
fdisk /dev/sdc
mkfs.ext3 /dev/sdc1
mount /dev/sdc1 /mnt
cp /some/data /mnt
sync

On Thu, 29 May 2008, Andrew Morton wrote:

> On Thu, 29 May 2008 16:39:25 -0700 (PDT)
> bugme-daemon@bugzilla.kernel.org wrote:
> 
> > http://bugzilla.kernel.org/show_bug.cgi?id=10834
...
> > besides this bug, the name "g_file_storage" sucks. isn`t that a "virtual
> usb
> > stick/mass storage emulator" ? ;)

It is not.  For one thing, it isn't virtual (although it is an
emulator).  For another, it isn't just an emulation of a USB memory 
stick, since it can also emulate a USB card reader.

In fact, g_file_storage is short for "file-backed storage gadget".  
(Read the source code if you don't believe this.)  I had in mind at one
time writing a second driver that would act as a "pass-through" gadget,
handing SCSI commands received over the USB bus to a real SCSI device.  
It would be a "SCSI-backed storage gadget".  But I never wrote it;
their were some technical difficulties and the whole thing seemed
relatively uninteresting once g_file_storage was working.

Alan Stern

The usb-storage debugging log doesn't give the right information.  You should turn off CONFIG_USB_STORAGE_DEBUG and instead turn on CONFIG_USB_GADGET_DEBUG.  Also, add "#define VERBOSE_DEBUG" near the start of drivers/usb/gadget/file_storage.c.

The log for the fdisk and mkfs commands aren't important; what matters is when you try to mount the new partition and copy the data file.

thanks for looking at this.
i think i can test on friday

Created attachment 16408 [details]
debug output

here is the requested information. mind that line "Jun  6 05:30:08 test root: now, after format and mkfs.ext i'm mounting sdc1" - thats where i mounted /dev/sdc1

Created attachment 16413 [details]
Use SG iterators in the USB scatter-gather library

This patch may take care of the problem.  It looks like the scatter-gather chaining conversion last fall didn't fix up all the places it should have.

thanks.
i tried the patch, but it doesn`t seem to make a difference

can you reproduce the problem ?

Created attachment 16440 [details]
Test for invalid URB parameters

I tried but it worked okay, not problems.  Probably the bug depends on the amount of memory available and the usage pattern.

Try using this diagnostic patch as well as the earlier one...  And also turn on CONFIG_USB_DEBUG.  For this test we won't need CONFIG_USB_GADGET_DEBUG or the verbose debugging in file_storage.c.

hi alan, 

i`m currently lacking time for testing. i tested one time yesterday, but it didn`t 
give any useful log output. i`m not sure if i did something wrong . i cannot retry before next week.

Any news?

thanks for asking, alan. unfortunately i was too busy for the last weeks and even worse, the power-supply of that box blew some days ago.  i hope i can give so some more input soon.

Closing stale bug