It's difficult to tell without timestamps, but this looks like a SCSI revalidation bug.
That is, the device reports very late that it is just initializing. The SCSI layer sees this as a media-change, but then doesn't revalidate properly. Since the first access is from vfat trying to determine if this is actually a vfat partition, when it fails you get the FAT error. Since 'auto' tries all known filesystems in order, the first one tried fails because of this error but FAT eventually succeds (once the state is cleared). Matt On Fri, Apr 28, 2006 at 09:24:51AM +0200, Patrick Agrain wrote: > Hi all, > > I have a mount problem which occurs only on the first try after a replug of > any available USB2.0 Memory Key. > The EHCI controller and USB storage drivers are from 2.4.32 kernel (Yes, I > know ;-) > > Console output: > [EMAIL PROTECTED] root]# mount -t vfat /dev/sda1 /mnt/usbdisk/ > I/O error: dev 08:01, sector 0 > FAT: unable to read boot sector > mount: wrong fs SCSI device sda: 251904 512-byte hdwr sectors (129 MB) > type, bad optionsda: Write Protect is off > , bad superblock sda1 on /dev/sda1, > > or too many mounted file systems > > The second try always succeeds. > Replacing 'vfat' by 'auto' is always successful, even on the first try. > > Something weird happens on the first READ_10 operation (see below). > > Following is the dmesg output from unplug - replug - mount operations : > usb-storage: -- releasing main URB > usb-storage: -- usb_unlink_urb() returned -19 > usb.c: kusbd: /sbin/hotplug remove 3 > ehci_hcd 00:1d.7: free_config 3 devnum 3 > ehci_hcd 00:1d.7: GetStatus port 4 status 001803 POWER sig=j CSC CONNECT > hub.c: port 4 connection change > hub.c: port 4, portstatus 501, change 1, 480 Mb/s > hub.c: port 4 of hub 1 not reset yet, waiting 10ms > hub.c: port 4 of hub 1 not reset yet, waiting 10ms > ehci_hcd 00:1d.7: port 4 high speed > ehci_hcd 00:1d.7: GetStatus port 4 status 001005 POWER sig=se0 PE CONNECT > hub.c: new USB device 00:1d.7-4, assigned address 4 > usb.c: kmalloc IF df9cf920, numif 1 > usb.c: new device strings: Mfr=1, Product=2, SerialNumber=3 > usb-storage: act_altsettting is 0 > usb-storage: id_index calculated to be: 94 > usb-storage: Array length appears to be: 96 > usb-storage: USB Mass Storage device detected > usb-storage: Endpoints: In: 0xc1804bd0 Out: 0xc1804be4 Int: 0xc1804bf8 > (Period 4) > usb.c: USB device number 4 default language ID 0x409 > usb-storage: Found existing GUID 0d7d1600000048510300047c > WARNING: USB Mass Storage data integrity not assured > USB Mass Storage device found at 4 > usb.c: usb-storage driver claimed interface df9cf920 > usb.c: kusbd: /sbin/hotplug add 4 > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command START_STOP (6 bytes) > usb-storage: 1b 00 00 00 01 00 06 08 20 09 06 08 > usb-storage: Bulk command S 0x43425355 T 0x59 Trg 0 LUN 0 L 0 F 0 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x59 R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command START_STOP (6 bytes) > usb-storage: 1b 00 00 00 01 00 00 00 00 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x5a Trg 0 LUN 0 L 0 F 0 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x5a R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 00 00 00 20 00 00 01 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x5b Trg 0 LUN 0 L 512 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 512 bytes > usb-storage: usb_stor_bulk_msg() returned -32 xferred 0/512 > usb-storage: clearing endpoint halt for pipe 0xc0008480 > usb-storage: usb_stor_clear_halt: result=0 > usb-storage: usb_stor_transfer_partial(): unknown error > usb-storage: Bulk data transfer result 0x2 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x5b R 0 Stat 0x1 > usb-storage: -- transport indicates command failure > usb-storage: Issuing auto-REQUEST_SENSE > usb-storage: Bulk command S 0x43425355 T 0x5c Trg 0 LUN 0 L 18 F 128 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 18 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 18/18 > usb-storage: usb_stor_transfer_partial(): transfer complete > usb-storage: Bulk data transfer result 0x0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x5c R 0 Stat 0x0 > usb-storage: -- Result from auto-sense is 0 > usb-storage: -- code: 0x70, key: 0x6, ASC: 0x28, ASCQ: 0x0 > usb-storage: Unit Attention: not ready to ready transition > usb-storage: scsi cmd done, result=0x2 > usb-storage: *** thread sleeping. > I/O error: dev 08:01, sector 0 > FAT: unable to read boot sector > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command START_STOP (6 bytes) > usb-storage: 1b 00 00 00 01 00 00 00 28 00 00 00 > usb-storage: Bulk command S 0x43425355 T 0x5d Trg 0 LUN 0 L 0 F 0 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x5d R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > VFS: Disk change detected on device sd(8,1) > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command TEST_UNIT_READY (6 bytes) > usb-storage: 00 00 00 00 00 00 00 00 00 00 5d de > usb-storage: Bulk command S 0x43425355 T 0x5e Trg 0 LUN 0 L 0 F 0 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x5e R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command READ_CAPACITY (10 bytes) > usb-storage: 25 00 00 00 00 00 00 00 00 00 5d de > usb-storage: Bulk command S 0x43425355 T 0x5f Trg 0 LUN 0 L 8 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 8 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 8/8 > usb-storage: usb_stor_transfer_partial(): transfer complete > usb-storage: Bulk data transfer result 0x0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x5f R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > SCSI device sda: 251904 512-byte hdwr sectors (129 MB) > usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command MODE_SENSE (6 bytes) > usb-storage: 1a 00 3f 00 ff 00 00 00 00 00 5d de > usb-storage: Bulk command S 0x43425355 T 0x60 Trg 0 LUN 0 L 255 F 128 CL 6 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 255 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 36/255 > usb-storage: Bulk data transfer result 0x1 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x60 R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > sda: Write Protect is off > sda:<7>usb-storage: queuecommand() called > usb-storage: *** thread awakened. > usb-storage: Command READ_10 (10 bytes) > usb-storage: 28 00 00 00 00 00 00 00 08 00 5d de > usb-storage: Bulk command S 0x43425355 T 0x61 Trg 0 LUN 0 L 4096 F 128 CL 10 > usb-storage: Bulk command transfer result=0 > usb-storage: usb_stor_transfer_partial(): xfer 4096 bytes > usb-storage: usb_stor_bulk_msg() returned 0 xferred 4096/4096 > usb-storage: usb_stor_transfer_partial(): transfer complete > usb-storage: Bulk data transfer result 0x0 > usb-storage: Attempting to get CSW... > usb-storage: Bulk status result = 0 > usb-storage: Bulk status Sig 0x53425355 T 0x61 R 0 Stat 0x0 > usb-storage: scsi cmd done, result=0x0 > usb-storage: *** thread sleeping. > sda1 > > Thanks in advance for any information about this behavior. > Regards, > Patrick Agrain > > > > ------------------------------------------------------- > Using Tomcat but need to do more? Need to support web services, security? > Get stuff done quickly with pre-integrated technology to make your job > easier > Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo > http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642 > _______________________________________________ > linux-usb-devel@lists.sourceforge.net > To unsubscribe, use the last form field at: > https://lists.sourceforge.net/lists/listinfo/linux-usb-devel -- Matthew Dharm Home: [EMAIL PROTECTED] Maintainer, Linux USB Mass Storage Driver I'm a pink gumdrop! How can anything be worse?!! -- Erwin User Friendly, 10/4/1998
pgpqjHsBzAe4J.pgp
Description: PGP signature
