Bug 176584

What was the last working kernel, if any? The newer the better (smaller diff).

No, I tried the previous kernel, one of my 2.6.13 (can't remember which, but I
think it was the last one before .14) and a 2.6.11.  None were successful.

Have tried some suggestions from fedoraforum.org, such as:

echo Y > /sys/module/usbcore/parameters/old_scheme_first

adding/removing usb kernel modules (uhci_hcd), but none really helped.

More info:

I have swapped the mp3 player and san disk card for a brand new one from the
store, and it behaves exactly the same way.  So I don't believe the hardware is
the cause, although I am still using the same USB cable as before.  I would
think that if the cable were the problem, I'd see errors on MacOS X 10.3.9 and
Windows XP SP2, which I don't.

I have reformatted the San Disk card from its default of FAT16 to FAT32, but it
made no difference either.

Very well. Since the device did not work with Linux before, making it work
requires some guesswork.

Please capture a usbmon trace for me. If kernel-doc is installed, a howto
would be in /usr/share/doc/kernel-doc-2.6.14/Documentation/usb/usbmon.txt.
Do not drop the trace into the comment window, attach to the bug instead.

Also... can you build your own kernels, or will you need binaries?

I've installed the kernel doc and created a usbmon output file for you.  I've
also logged the commands I used, just in case I did the trace wrong and you need
to see where I made a mistake.

I'll probably need kernel binaries.  I've got about a 40% success rate on kernel
builds, and I've never tried to build one with the new Fedora kernel build
procedure.  I can try, though, if you want me to.

Created attachment 122598 [details]
usbmon trace on latest fc4 kernel

Created attachment 122599 [details]
commands used to create usbmon trace

Created attachment 122605 [details]
2nd run of usbmon, on different computer

Just in case more data is helpful, I've attached a 2nd run of usbmon which I
produced on a different computer than the first usbmon run.  FWIW, this run was
using the computer that I originally filed the bug report with, and has all of
the config info above.

Traces were collected correctly, thanks. I see the error -71 when reading
the 64-byte descriptor, but that does not preclude the device from enumerating,
so it is not that important. However, in neither of the two traces I saw any
I/O errors when reading the data, which is the main problem. I wish dmesg was
saved too. Were there any?

Created attachment 122673 [details]
dmesg output with usb mp3 player attached

This is dmesg output taken after I've had my mp3 player connected for a few
minutes.  Do you need it collected as I do a usbmon trace, or is this good
enough?  Is there anything else you need?

I need the trace which shows I/O errors and a dmesg to match, from the same
test run.

Created attachment 122675 [details]
usbmon trace for 1/1/06

3rd usbmon trace, goes with dmesg and varlogmessages output files.

Created attachment 122676 [details]
dmesg output from 1/1/06 (3-usbmon) trace

This is the dmesg output after I ran the 3-usbmon trace on 1/1/06.

Created attachment 122677 [details]
errors from /var/log/messages that showed up during 3-usbmon trace on 1/1/06

These are the errors from /var/log/messages that showed up when I was running a
usbmon trace on 1/1/06

Anything else I can provide to help out with this?  Were the last traces what
you wanted?

This is a mass-update to all currently open kernel bugs.

A new kernel update has been released (Version: 2.6.15-1.1830_FC4)
based upon a new upstream kernel release.

Please retest against this new kernel, as a large number of patches
go into each upstream release, possibly including changes that
may address this problem.

This bug has been placed in NEEDINFO_REPORTER state.
Due to the large volume of inactive bugs in bugzilla, if this bug is
still in this state in two weeks time, it will be closed.

Should this bug still be relevant after this period, the reporter
can reopen the bug at any time. Any other users on the Cc: list
of this bug can request that the bug be reopened by adding a
comment to the bug.

If this bug is a problem preventing you from installing the
release this version is filed against, please see bug 169613.

Thank you.

This bug is still present and acts/looks the same as before..  Please let me
know if more usbmon traces need to be run, or the info contained in the prevous
traces is sufficient.  A snippet from my messages file: 

Feb  3 18:28:42 slacker kernel:   Vendor: GENERIC   Model: MP3 PLAYER       
Rev: 0100
Feb  3 18:28:42 slacker kernel:   Type:   Direct-Access                     
ANSI SCSI revision: 00
Feb  3 18:28:43 slacker kernel: SCSI device sda: 1979905 512-byte hdwr sectors
(1014 MB)
Feb  3 18:28:43 slacker kernel: sda: Write Protect is off
Feb  3 18:28:43 slacker kernel: sda: assuming drive cache: write through
Feb  3 18:28:43 slacker kernel: SCSI device sda: 1979905 512-byte hdwr sectors
(1014 MB)
Feb  3 18:28:43 slacker kernel: sda: Write Protect is off
Feb  3 18:28:43 slacker kernel: sda: assuming drive cache: write through
Feb  3 18:28:43 slacker kernel:  sda: sda1
Feb  3 18:28:43 slacker kernel: sd 0:0:0:0: Attached scsi removable disk sda
Feb  3 18:28:43 slacker scsi.agent[3078]: disk at
/devices/pci0000:00/0000:00:10.2/usb4/4-2/4-2:1.0/host0/target0:0:0/0:0:0:0
Feb  3 18:28:44 slacker kernel: sd 0:0:0:0: SCSI error: return code = 0x10070000
Feb  3 18:28:44 slacker kernel: end_request: I/O error, dev sda, sector 64
Feb  3 18:28:44 slacker kernel: Buffer I/O error on device sda, logical block 64
Feb  3 18:28:44 slacker kernel: sd 0:0:0:0: SCSI error: return code = 0x10070000

Just to make sure my last comment was clear, I re-tested again with the latest
errata from 2/3/06, which includes kernel-2.6.15-1.1830_FC4 & udev-071-0.FC4.2

Bug is still present in kernel 2.6.15-1.1831_FC4.

OK, I'm tearing my hair now. The first usbmon trace from 2005/12/27 did have
the errors, only not what I expected, so I did not notice them until now.

Whenever we ask the device to transfer more than 32KB at a time, the residue
count overflows in the firmware. Then, it reports a bogus residue (but no
SCSI error), which usb-storage reports as a SCSI error.

A usual solution is to add the device to unusual_devs.h with the flag
US_FL_IGNORE_RESIDUE. I am not sure how safe this is though, since
something overflows inside the device.

--- linux-2.6.16-rc2/drivers/usb/storage/unusual_devs.h	2006-02-11
00:32:15.000000000 -0800
+++ linux-2.6.16-rc2-lem/drivers/usb/storage/unusual_devs.h	2006-02-14
23:40:58.000000000 -0800
@@ -113,6 +113,12 @@ UNUSUAL_DEV(  0x0419, 0xaaf6, 0x0100, 0x
 		US_SC_DEVICE, US_PR_DEVICE, NULL,
 		US_FL_IGNORE_RESIDUE ),
 
+/* Reported by Pete Zaitcev <zaitcev>, bz#176584 */
+UNUSUAL_DEV(  0x0420, 0x0001, 0x0100, 0x0100,
+		"GENERIC", "MP3 PLAYER", /* MyMusix PD-205 on the outside. */
+		US_SC_DEVICE, US_PR_DEVICE, NULL,
+		US_FL_IGNORE_RESIDUE ),
+
 /* Reported by Olaf Hering <olh> from novell bug #105878 */
 UNUSUAL_DEV(  0x0424, 0x0fdc, 0x0210, 0x0210,
 		"SMSC",

I'm so desperate to get my mp3 player working with fedora that I'll give it a
shot!  I'm running 2.6.15-1.1831_FC4 at the moment, so should I apply this patch
to it or do you have a test RPM that I should try?

It would be best if you built it. Doing an official test is such a pain.
And I'm sending this upstream anyway.

I tried the patch with the 2.6.15-1.1831_FC4 source.  I don't think I messed up
the patching or the kernel compile, but maybe so.  Anyway, the mp3 player still
doesn't work.  These are from /var/log/messages, the usbmon trace is attached. 
One thing that has changed are the number of I/O errors.  There are far fewer of
them in the messages file now.

Feb 15 22:40:23 slacker kernel: usb 4-2: USB disconnect, address 5
Feb 15 22:40:25 slacker kernel: usb 4-2: new full speed USB device using
uhci_hcd and address 6
Feb 15 22:40:25 slacker kernel: usb 4-2: device descriptor read/64, error -71
Feb 15 22:40:26 slacker kernel: usb 4-2: device not accepting address 6, error -71
Feb 15 22:40:26 slacker kernel: usb 4-2: new full speed USB device using
uhci_hcd and address 7
Feb 15 22:40:26 slacker kernel: scsi2 : SCSI emulation for USB Mass Storage devices
Feb 15 22:40:31 slacker kernel:   Vendor: GENERIC   Model: MP3 PLAYER       
Rev: 0100
Feb 15 22:40:31 slacker kernel:   Type:   Direct-Access                     
ANSI SCSI revision: 00Feb 15 22:40:31 slacker kernel: SCSI device sda: 1979905
512-byte hdwr sectors (1014 MB)
Feb 15 22:40:31 slacker kernel: sda: Write Protect is off
Feb 15 22:40:31 slacker kernel: sda: assuming drive cache: write through
Feb 15 22:40:31 slacker kernel: SCSI device sda: 1979905 512-byte hdwr sectors
(1014 MB)
Feb 15 22:40:31 slacker kernel: sda: Write Protect is off
Feb 15 22:40:31 slacker kernel: sda: assuming drive cache: write through
Feb 15 22:40:31 slacker kernel:  sda: sda1
Feb 15 22:40:31 slacker kernel: sd 2:0:0:0: Attached scsi removable disk sda
Feb 15 22:40:31 slacker scsi.agent[3338]: disk at
/devices/pci0000:00/0000:00:10.2/usb4/4-2/4-2:1.0/host2/target2:0:0/2:0:0:0
Feb 15 22:40:32 slacker kernel: printk: 145 messages suppressed.
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983360
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983361
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983362
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983363
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983364
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983365
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983366
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983367
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983360
Feb 15 22:40:32 slacker kernel: Buffer I/O error on device sda1, logical block
1983361
Feb 15 22:40:39 slacker kernel: usb 4-2: USB disconnect, address 7

Created attachment 124739 [details]
usbmon with patch applied

usbmon with patch in place.

Hmm. So, the device has 1979905 blocks (probably wrong reporting, too - odd
number of blocks), but something accesses block number 1983360. Naturally,
it does not work. We know that this is not the partitioning code, because
it happens after the partition was recognized. So, FAT or FAT32 (vfat).

Is this thing formattable in Windows?

Yes, it is formattable in Windows.  One of the first things I did when I
experienced this error was to reformat it with FAT32 using a Windows XP system.

I'm afraid the formatter in XP actually reads the so-called "BPB" or BIOS
Parameters Block, which is sent incorrectly. How about going over it with
fdisk and making a smaller partition manually?

I can give that a shot.

What do I need to do with fdisk to get around the SCSI I/O errors I get when I
plug in the device?  Will those errors prevent me from making a valid parition
with fdisk?

Delete the partition which XP created automatically and create a partition
with 1979904 blocks (989952 KB). Then, format f: or what is the right drive
to put the FAT32 on it (be very careful not to format a hard disk though!).

What follows is the most beautiful thing I've seen in /var/log/messages in some
time!  ;)

Feb 17 21:42:42 slacker kernel: hub 1-0:1.0: over-current change on port 5
Feb 17 21:42:42 slacker kernel: hub 1-0:1.0: over-current change on port 6
Feb 17 21:42:43 slacker kernel: usb 4-2: new full speed USB device using
uhci_hcd and address 4
Feb 17 21:42:43 slacker kernel: scsi2 : SCSI emulation for USB Mass Storage devices
Feb 17 21:42:48 slacker kernel:   Vendor: GENERIC   Model: MP3 PLAYER       
Rev: 0100
Feb 17 21:42:48 slacker kernel:   Type:   Direct-Access                     
ANSI SCSI revision: 00
Feb 17 21:42:48 slacker kernel: SCSI device sda: 1979905 512-byte hdwr sectors
(1014 MB)
Feb 17 21:42:48 slacker kernel: sda: Write Protect is off
Feb 17 21:42:48 slacker kernel: sda: assuming drive cache: write through
Feb 17 21:42:48 slacker kernel: SCSI device sda: 1979905 512-byte hdwr sectors
(1014 MB)
Feb 17 21:42:48 slacker kernel: sda: Write Protect is off
Feb 17 21:42:48 slacker kernel: sda: assuming drive cache: write through
Feb 17 21:42:48 slacker kernel:  sda: sda1
Feb 17 21:42:48 slacker kernel: sd 2:0:0:0: Attached scsi removable disk sda
Feb 17 21:42:48 slacker scsi.agent[3230]: disk at
/devices/pci0000:00/0000:00:10.2/usb4/4-2/4-2:1.0/host2/target2:0:0/2:0:0:0
Feb 17 21:42:49 slacker fstab-sync[3273]: added mount point /media/MP3PLAYER for
/dev/sda1
Feb 17 21:42:49 slacker kernel: SELinux: initialized (dev sda1, type vfat), uses
genfs_contexts
<snip>
Feb 17 22:34:22 slacker kernel: usb 4-2: USB disconnect, address 4
Feb 17 22:34:23 slacker fstab-sync[3858]: removed mount point /media/MP3PLAYER
for /dev/sda1

In short, it works now.  I used my wife's ibook to erase the mp3 player's san
disk card, then formated it as a MS-DOS parition of size 966.75MB.  This
reformat, plus the patch you created, solved the problem.  I have copied over
almost 800 MB of podcasts and mp3s so far w/o any hiccups.  The patch you made
is necessary.  When I tried to use the player with the new formatted disk on the
non-patched kernel, I still got IO errors.

I had to resort to the ibook for the reformat because I was unable to use fdisk
to delete the old parition.  fdisk didn't recognize /dev/sda, and /dev/sda1 had
cylinder issues that I couldn't get around.  No matter what value I used, it
never successfully wrote new parition table info to the card.  I probably didn't
use the right cylinder values, but my Google searches were fruitless and didn't
want to spend all night researching it unless I had to.  I didn't have much luck
with parted either, although I'm not as familiar with that program.

So, will this patch likely be included in the FC4 kernels from now on, or will I
have to patch all of my upcoming kernels myself?  It took my poor system forever
to compile the last one!  :)

Well... I suppose I can add this to FC4. Usually we do it only when upstream
commits to it, and I haven't heard back from Phil yet. But in this case it's
pretty clear that the patch is needed and I'll have it upstream one way or
the other.

By the way, worst comes to worst, it probably would work to set max sectors
before mounting on an unpatched kernel, with this:
 echo 31 > /sys/block/sda/queue/max_sectors_kb
But even it that works, it certainly is a pain and not compatible with the
desktop GUI anyway.

Is this patch included in kernel-2.6.15-1.1833_FC4?