I am seeing strange behaviour with my USB stick. I can mount it
the first time it is inserted, but after unmounting, unplugging, and
plugging in again, it can't be mounted.

I have also seen one case where it was possible to mount it the second
time round, but got a kernel bug report dumped to syslog when I
unmounted it.

I'm using udev 0.031. Kernel is Debian 2.6.8. hal is managing
/etc/fstab. The USB stick is a SanDisk Cruzer Mini

Here's the kernel bug dump:

Oct  1 09:54:20 kuhaugen kernel: usb-storage: Error in device_reset: invalid state 0
Oct  1 09:55:22 kuhaugen kernel: ------------[ cut here ]------------
Oct  1 09:55:22 kuhaugen kernel: kernel BUG at drivers/block/as-iosched.c:312!
Oct  1 09:55:22 kuhaugen kernel: invalid operand: 0000 [#1]
Oct  1 09:55:22 kuhaugen kernel: PREEMPT 
Oct  1 09:55:22 kuhaugen kernel: Modules linked in: sd_mod usb_storage scsi_mod ipv6 
lp binfmt_misc ds ipt_state ip_conntrack iptable_filter ip_tables af_packet e100 
yenta_socket pcmcia_core snd_intel8x0 snd_ac97_codec snd_pcm_oss snd_mixer_oss snd_pcm 
snd_timer snd_page_alloc gameport snd_mpu401_uart snd_rawmidi snd_seq_device snd 
soundcore hw_random uhci_hcd usbcore shpchp pciehp pci_hotplug intel_agp agpgart 
parport_pc parport floppy irtty_sir sir_dev pcspkr rtc nls_iso8859_1 nls_cp437 
capability commoncap tsdev ircomm_tty evdev ircomm irda crc_ccitt mousedev psmouse 
eepro100 mii apm vfat fat ext3 jbd mbcache ide_generic piix ide_disk ide_core unix 
font vesafb cfbcopyarea cfbimgblt cfbfillrect
Oct  1 09:55:22 kuhaugen kernel: CPU:    0
Oct  1 09:55:22 kuhaugen kernel: EIP:    0060:[as_find_arq_hash+153/176]    Not tainted
Oct  1 09:55:22 kuhaugen kernel: EFLAGS: 00010046   (2.6.8-1-686) 
Oct  1 09:55:22 kuhaugen kernel: EIP is at as_find_arq_hash+0x99/0xb0
Oct  1 09:55:22 kuhaugen kernel: eax: 00000000   ebx: 00000000   ecx: d7a49260   edx: 
08085dfc
Oct  1 09:55:22 kuhaugen kernel: esi: 00000000   edi: 00000219   ebp: 00000000   esp: 
d691fb84
Oct  1 09:55:22 kuhaugen kernel: ds: 007b   es: 007b   ss: 0068
Oct  1 09:55:22 kuhaugen kernel: Process famd (pid: 3572, threadinfo=d691e000 
task=d7990620)
Oct  1 09:55:22 kuhaugen kernel: Stack: c01180c2 d7a10030 bffff8b8 00000000 d7a49260 
0000021a 00000000 c0201fcd 
Oct  1 09:55:22 kuhaugen kernel:        d7a49260 00000219 00000000 00000000 dc86267a 
d7a49260 00000000 d664c02c 
Oct  1 09:55:22 kuhaugen kernel:        00000000 00000000 c01f90e9 d664c02c d691fc04 
cabdf0e0 c01fc2c7 d664c02c 
Oct  1 09:55:22 kuhaugen kernel: Call Trace:
Oct  1 09:55:22 kuhaugen kernel:  [activate_task+98/128] activate_task+0x62/0x80
Oct  1 09:55:22 kuhaugen kernel:  [as_merge+285/512] as_merge+0x11d/0x200
Oct  1 09:55:22 kuhaugen kernel:  [elv_merge+41/48] elv_merge+0x29/0x30
Oct  1 09:55:22 kuhaugen kernel:  [__make_request+183/1376] __make_request+0xb7/0x560
Oct  1 09:55:22 kuhaugen kernel:  [generic_make_request+362/496] 
generic_make_request+0x16a/0x1f0
Oct  1 09:55:22 kuhaugen kernel:  [autoremove_wake_function+0/96] 
autoremove_wake_function+0x0/0x60
Oct  1 09:55:22 kuhaugen kernel:  [autoremove_wake_function+0/96] 
autoremove_wake_function+0x0/0x60
Oct  1 09:55:22 kuhaugen kernel:  [submit_bio+93/256] submit_bio+0x5d/0x100
Oct  1 09:55:22 kuhaugen kernel:  [end_buffer_read_sync+0/48] 
end_buffer_read_sync+0x0/0x30
Oct  1 09:55:22 kuhaugen kernel:  [submit_bh+97/336] submit_bh+0x61/0x150
Oct  1 09:55:22 kuhaugen kernel:  [__bread_slow+74/128] __bread_slow+0x4a/0x80
Oct  1 09:55:22 kuhaugen kernel:  [__bread+61/80] __bread+0x3d/0x50
Oct  1 09:55:22 kuhaugen kernel:  [__crc_blk_queue_start_tag+2580343/4471782] 
fat__get_entry+0xb6/0x194 [fat]
Oct  1 09:55:22 kuhaugen kernel:  [__crc_blk_queue_start_tag+2565532/4471782] 
fat_readdirx+0xd3b/0xe30 [fat]
Oct  1 09:55:22 kuhaugen kernel:  [sock_sendmsg+157/192] sock_sendmsg+0x9d/0xc0
Oct  1 09:55:22 kuhaugen kernel:  [__crc_blk_queue_start_tag+2462204/4471782] 
vfat_cmpi+0x3b/0xb0 [vfat]
Oct  1 09:55:22 kuhaugen kernel:  [__d_lookup+358/368] __d_lookup+0x166/0x170
Oct  1 09:55:22 kuhaugen kernel:  [__crc_blk_queue_start_tag+2462204/4471782] 
vfat_cmpi+0x3b/0xb0 [vfat]
Oct  1 09:55:22 kuhaugen kernel:  [__d_lookup+358/368] __d_lookup+0x166/0x170
Oct  1 09:55:22 kuhaugen kernel:  [__crc_blk_queue_start_tag+2462204/4471782] 
vfat_cmpi+0x3b/0xb0 [vfat]
Oct  1 09:55:22 kuhaugen kernel:  [__d_lookup+358/368] __d_lookup+0x166/0x170
Oct  1 09:55:22 kuhaugen kernel:  [dput+49/544] dput+0x31/0x220
Oct  1 09:55:22 kuhaugen kernel:  [link_path_walk+2635/3488] link_path_walk+0xa4b/0xda0
Oct  1 09:55:22 kuhaugen kernel:  [__crc_blk_queue_start_tag+2565830/4471782] 
fat_readdir+0x35/0x40 [fat]
Oct  1 09:55:22 kuhaugen kernel:  [filldir64+0/256] filldir64+0x0/0x100
Oct  1 09:55:22 kuhaugen kernel:  [vfs_readdir+165/192] vfs_readdir+0xa5/0xc0
Oct  1 09:55:22 kuhaugen kernel:  [filldir64+0/256] filldir64+0x0/0x100
Oct  1 09:55:22 kuhaugen kernel:  [sys_getdents64+110/170] sys_getdents64+0x6e/0xaa
Oct  1 09:55:22 kuhaugen kernel:  [filldir64+0/256] filldir64+0x0/0x100
Oct  1 09:55:22 kuhaugen kernel:  [syscall_call+7/11] syscall_call+0x7/0xb
Oct  1 09:55:22 kuhaugen kernel: Code: 0f 0b 38 01 09 a0 29 c0 eb ac 8d b6 00 00 00 00 
8d bc 27 00 
Oct  1 09:55:22 kuhaugen kernel:  <6>note: famd[3572] exited with preempt_count 2

The sequence of actions which led up to this was:

- Reboot
- Insert stick
  There's now an entry in fstab
- Remove stick
  fstab entry is gone
- Insert stick
  udev logs to syslog that it's creating sdb1, sda1 entry was added to fstab
- mount from command line 'mount -t vfat /dev/sdb1 <mountpoint>
  ls <mountpoint> looks OK
- umount
  The kernel bug message shown above is logged to syslog.

I've seen the kernel bug dump only once. More typical syslogs:

Plugging in for the first time:

Sep 30 10:42:14 kuhaugen kernel: usb 2-1: new full speed USB device using address 2
Sep 30 10:42:15 kuhaugen kernel: SCSI subsystem initialized
Sep 30 10:42:15 kuhaugen kernel: Initializing USB Mass Storage driver...
Sep 30 10:42:15 kuhaugen kernel: scsi0 : SCSI emulation for USB Mass Storage devices
Sep 30 10:42:15 kuhaugen kernel:   Vendor: Generic   Model: STORAGE DEVICE    Rev: 1.25
Sep 30 10:42:15 kuhaugen kernel:   Type:   Direct-Access                      ANSI 
SCSI revision: 02
Sep 30 10:42:15 kuhaugen usb.agent[4439]:      usb-storage: loaded successfully
Sep 30 10:42:15 kuhaugen kernel: USB Mass Storage device found at 2
Sep 30 10:42:15 kuhaugen kernel: usbcore: registered new driver usb-storage
Sep 30 10:42:15 kuhaugen kernel: USB Mass Storage support registered.
Sep 30 10:42:15 kuhaugen scsi.agent[4503]: disk at 
/devices/pci0000:00/0000:00:1d.1/usb2/2-1/2-1:1.0/host0/0:0:0:0
Sep 30 10:42:15 kuhaugen kernel: SCSI device sda: 256000 512-byte hdwr sectors (131 MB)
Sep 30 10:42:15 kuhaugen kernel: sda: Write Protect is off
Sep 30 10:42:15 kuhaugen kernel: sda: Mode Sense: 02 00 00 00
Sep 30 10:42:15 kuhaugen kernel: sda: assuming drive cache: write through
Sep 30 10:42:15 kuhaugen udev: creating device node '/dev/sda'
Sep 30 10:42:15 kuhaugen kernel:  /dev/scsi/host0/bus0/target0/lun0: p1
Sep 30 10:42:15 kuhaugen kernel: Attached scsi removable disk sda at scsi0, channel 0, 
id 0, lun 0
Sep 30 10:42:15 kuhaugen udev: creating device node '/dev/sda1'
Sep 30 10:42:16 kuhaugen fstab-sync[4539]: added mount point /media/usbdisk for 
/dev/sda1
Sep 30 10:44:01 kuhaugen /USR/SBIN/CRON[4586]: (jk) CMD 
(/home/jk/net-status/bin/cpumem)

hal/gnome-vfs-manager now mounts it. Everything is fine. I unmount it
successfully, and unplug the device:

Sep 30 10:46:17 kuhaugen udev: removing device node '/dev/sda1'
Sep 30 10:46:17 kuhaugen udev: removing device node '/dev/sda'
Sep 30 10:46:17 kuhaugen kernel: usb 2-1: USB disconnect, address 2
Sep 30 10:46:17 kuhaugen fstab-sync[4652]: removed mount point /media/usbdisk for 
/dev/sda1

Now I plug it on for the second time:

Sep 30 10:46:40 kuhaugen kernel: usb 2-1: new full speed USB device using address 3
Sep 30 10:46:40 kuhaugen kernel: scsi1 : SCSI emulation for USB Mass Storage devices
Sep 30 10:46:40 kuhaugen kernel:   Vendor: Generic   Model: STORAGE DEVICE    Rev: 1.25
Sep 30 10:46:40 kuhaugen kernel:   Type:   Direct-Access                      ANSI 
SCSI revision: 02
Sep 30 10:46:41 kuhaugen kernel: sda : unsupported sector size -402718720.

Note the garbage sector size.

Sep 30 10:46:41 kuhaugen kernel: SCSI device sda: 0 -402718720-byte hdwr sectors (0 MB)
Sep 30 10:46:41 kuhaugen kernel: sda: Write Protect is off
Sep 30 10:46:41 kuhaugen kernel: sda: Mode Sense: 02 00 00 00
Sep 30 10:46:41 kuhaugen kernel: sda: assuming drive cache: write through
Sep 30 10:46:41 kuhaugen kernel: Attached scsi removable disk sda at scsi1, channel 0, 
id 0, lun 0
Sep 30 10:46:41 kuhaugen kernel: USB Mass Storage device found at 3
Sep 30 10:46:41 kuhaugen scsi.agent[4750]: disk at 
/devices/pci0000:00/0000:00:1d.1/usb2/2-1/2-1:1.0/host1/1:0:0:0
Sep 30 10:46:42 kuhaugen udev: creating device node '/dev/sda'

It's not possible to mount /dev/sda1. My first idea was that udev got
confused about which device it should create (no idea if that's
possible). Anyway, I restarted the computer with udev off, and tried
mounting both as /dev/sda1 and /dev/sdb1 the second time
round. Neither worked.

Another variant of the second plugging in:

Oct  1 10:06:35 kuhaugen kernel: usb 2-1: new full speed USB device using address 3
Oct  1 10:06:36 kuhaugen kernel: scsi1 : SCSI emulation for USB Mass Storage devices
Oct  1 10:06:36 kuhaugen kernel:   Vendor: Generic   Model: STORAGE DEVICE    Rev: 1.25
Oct  1 10:06:36 kuhaugen kernel:   Type:   Direct-Access                      ANSI 
SCSI revision: 02
Oct  1 10:06:46 kuhaugen hal.hotplug[4793]: timout(10000 ms) waiting for 
/devices/pci0000:00/0000:00:1d.1/usb2/2-1/2-1:1.0 
Oct  1 10:06:46 kuhaugen hal.hotplug[4803]: timout(10000 ms) waiting for 
/devices/pci0000:00/0000:00:1d.1/usb2/2-1/2-1:1.0/host1/1:0:0:0 
Oct  1 10:06:46 kuhaugen usb.agent[4816]:      usb-storage: already loaded
Oct  1 10:06:56 kuhaugen scsi.agent[4821]: Attribute 
/sys/devices/pci0000:00/0000:00:1d.1/usb2/2-1/2-1:1.0/host1/1:0:0:0/type does not exist


These modules are loaded when the stick is mounted:

Module                  Size  Used by
sd_mod                 21696  2 
usb_storage            68832  1 
scsi_mod              125196  2 sd_mod,usb_storage
ipv6                  264612  24 
lp                     11176  0 
binfmt_misc            11688  1 
ds                     18756  4 
ipt_state               2080  1 
ip_conntrack           35368  1 ipt_state
iptable_filter          2880  1 
ip_tables              18464  2 ipt_state,iptable_filter
af_packet              22600  0 
e100                   32608  0 
yenta_socket           21728  0 
pcmcia_core            70900  2 ds,yenta_socket
snd_intel8x0           36460  0 
snd_ac97_codec         70020  1 snd_intel8x0
snd_pcm_oss            55048  0 
snd_mixer_oss          20096  1 snd_pcm_oss
snd_pcm                98728  2 snd_intel8x0,snd_pcm_oss
snd_timer              25668  1 snd_pcm
snd_page_alloc         11752  2 snd_intel8x0,snd_pcm
gameport                4704  1 snd_intel8x0
snd_mpu401_uart         7968  1 snd_intel8x0
snd_rawmidi            25156  1 snd_mpu401_uart
snd_seq_device          8200  1 snd_rawmidi
snd                    57156  9 
snd_intel8x0,snd_ac97_codec,snd_pcm_oss,snd_mixer_oss,snd_pcm,snd_timer,snd_mpu401_uart,snd_rawmidi,snd_seq_device
soundcore              10336  1 snd
hw_random               5460  0 
uhci_hcd               33136  0 
usbcore               119012  4 usb_storage,uhci_hcd
shpchp                101996  0 
pciehp                 99084  0 
pci_hotplug            34640  2 shpchp,pciehp
intel_agp              22752  1 
agpgart                34696  1 intel_agp
parport_pc             35392  1 
parport                41832  2 lp,parport_pc
floppy                 61200  0 
irtty_sir               9152  2 
sir_dev                19244  1 irtty_sir
pcspkr                  3592  0 
rtc                    12760  0 
nls_iso8859_1           4032  2 
nls_cp437               5696  2 
capability              4520  0 
commoncap               7232  1 capability
tsdev                   7392  0 
ircomm_tty             40456  0 
evdev                   9600  0 
ircomm                 23044  1 ircomm_tty
irda                  197120  4 irtty_sir,sir_dev,ircomm_tty,ircomm
crc_ccitt               2144  1 irda
mousedev               10476  2 
psmouse                20360  0 
eepro100               30700  0 
mii                     5120  2 e100,eepro100
apm                    21100  2 
vfat                   14656  2 
fat                    46784  1 vfat
ext3                  127240  2 
jbd                    62616  1 ext3
mbcache                 9348  1 ext3
ide_generic             1408  0 
piix                   13440  1 
ide_disk               19296  5 
ide_core              139940  4 usb_storage,ide_generic,piix,ide_disk
unix                   28692  64 
font                    8320  0 
vesafb                  6656  0 
cfbcopyarea             3840  1 vesafb
cfbimgblt               3040  1 vesafb
cfbfillrect             3776  1 vesafb

Device inforamtion from usbview:

Cruzer Mini 
Manufacturer: SanDisk Corporation 
Serial Number: 000197057
Speed: 12Mb/s (full)
USB Version:  2.00
Device Class: 00(>ifc )
Device Subclass: 00
Device Protocol: 00
Maximum Default Endpoint Size: 64
Number of Configurations: 1
Vendor Id: 0781
Product Id: 8181
Revision Number:  1.25

What is going on here?

Jon Kåre


-------------------------------------------------------
This SF.net email is sponsored by: IT Product Guide on ITManagersJournal
Use IT products in your business? Tell us what you think of them. Give us
Your Opinions, Get Free ThinkGeek Gift Certificates! Click to find out more
http://productguide.itmanagersjournal.com/guidepromo.tmpl
_______________________________________________
[EMAIL PROTECTED]
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel

Reply via email to