Noticed in 2.6.9-rc4-mm1, still present in 2.6.9-mm1:
When a usb flash memory key is inserted, I get this report on syslog:
Oct 22 21:40:04 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001803 POWER sig=j CSC CONNECT
Oct 22 21:40:04 kefk kernel: hub 5-0:1.0: port 3, status 0501, change 0001,
480 Mb/s
Oct 22 21:40:04 kefk kernel: hub 5-0:1.0: debounce: port 3: total 100ms stable
100ms status 0x501
Oct 22 21:40:04 kefk kernel: hub 5-0:1.0: port 3 not reset yet, waiting 50ms
Oct 22 21:40:04 kefk kernel: ehci_hcd 0000:00:1d.7: port 3 high speed
Oct 22 21:40:04 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001005 POWER sig=se0 PE CONNECT
Oct 22 21:40:04 kefk kernel: usb 5-3: new high speed USB device using address
6
Oct 22 21:40:04 kefk kernel: usb 5-3: new device strings: Mfr=1, Product=2,
SerialNumber=3
Oct 22 21:40:04 kefk kernel: usb 5-3: default language 0x0409
Oct 22 21:40:04 kefk kernel: usb 5-3: Product: Mass storage
Oct 22 21:40:04 kefk kernel: usb 5-3: Manufacturer: USB
Oct 22 21:40:04 kefk kernel: usb 5-3: SerialNumber: 142E19413C2FCA34
Oct 22 21:40:04 kefk kernel: usb 5-3: hotplug
Oct 22 21:40:04 kefk kernel: usb 5-3: adding 5-3:1.0 (config #1, interface 0)
Oct 22 21:40:04 kefk kernel: usb 5-3:1.0: hotplug
Oct 22 21:40:05 kefk kernel: ub: sizeof ub_scsi_cmd 64 ub_dev 964
Oct 22 21:40:05 kefk kernel: ub 5-3:1.0: usb_probe_interface
Oct 22 21:40:05 kefk kernel: ub 5-3:1.0: usb_probe_interface - got id
Oct 22 21:40:05 kefk kernel: uba: device 6 capacity nsec 50 bsize 512
Oct 22 21:40:05 kefk kernel: uba: made changed
Oct 22 21:40:05 kefk kernel: uba: device 6 capacity nsec 1024000 bsize 512
Oct 22 21:40:05 kefk kernel: uba: device 6 capacity nsec 1024000 bsize 512
Oct 22 21:40:05 kefk kernel: uba: uba1
Oct 22 21:40:05 kefk kernel: uba: uba1
Oct 22 21:40:05 kefk kernel: kobject_register failed for uba1 (-17)
Oct 22 21:40:05 kefk kernel: [<c01f1f77>] kobject_register+0x51/0x5f
Oct 22 21:40:05 kefk kernel: [<c018467c>] add_partition+0xbb/0xf0
Oct 22 21:40:05 kefk kernel: [<c01847f4>] register_disk+0xee/0x11d
Oct 22 21:40:05 kefk kernel: [<c024b8e6>] add_disk+0x36/0x41
Oct 22 21:40:05 kefk kernel: [<c024b89c>] exact_match+0x0/0x7
Oct 22 21:40:05 kefk kernel: [<c024b8a3>] exact_lock+0x0/0xd
Oct 22 21:40:05 kefk kernel: [<f8c48e70>] ub_probe+0x291/0x2f4 [ub]
Oct 22 21:40:05 kefk kernel: [<c0298f0e>] usb_probe_interface+0xb8/0xe1
Oct 22 21:40:05 kefk kernel: [<c0243274>] bus_match+0x32/0x6a
Oct 22 21:40:05 kefk kernel: [<c024339c>] driver_attach+0x46/0x85
Oct 22 21:40:05 kefk kernel: [<c01f1f48>] kobject_register+0x22/0x5f
Oct 22 21:40:05 kefk kernel: [<c0243800>] bus_add_driver+0x91/0xcb
Oct 22 21:40:05 kefk kernel: [<c0298fe0>] usb_register+0x49/0x9f
Oct 22 21:40:05 kefk kernel: [<f8c4d03f>] ub_init+0x3f/0x5f [ub]
Oct 22 21:40:05 kefk kernel: [<c0131de7>] sys_init_module+0x160/0x246
Oct 22 21:40:05 kefk kernel: [<c0103d71>] sysenter_past_esp+0x52/0x71
Oct 22 21:40:05 kefk kernel: usbcore: registered new driver ub
After that, uba appears as /dev/uba, but /dev/uba1 is missing. I can create by
hand /dev/uba1 and access data on flash key, but if I umount and then remove
the key I get this oops:
Oct 22 21:45:05 kefk kernel: ehci_hcd 0000:00:1d.7: GetStatus port 3 status
001002 POWER sig=se0 CSC
Oct 22 21:45:05 kefk kernel: hub 5-0:1.0: port 3, status 0100, change 0001, 12
Mb/s
Oct 22 21:45:05 kefk kernel: usb 5-3: USB disconnect, address 6
Oct 22 21:45:05 kefk kernel: usb 5-3: usb_disable_device nuking all URBs
Oct 22 21:45:05 kefk kernel: usb 5-3: unregistering interface 5-3:1.0
Oct 22 21:45:05 kefk kernel: Unable to handle kernel NULL pointer dereference
at virtual address 00000050
Oct 22 21:45:05 kefk kernel: printing eip:
Oct 22 21:45:05 kefk kernel: c01862cf
Oct 22 21:45:05 kefk kernel: *pde = 00000000
Oct 22 21:45:05 kefk kernel: Oops: 0000 [#1]
Oct 22 21:45:05 kefk kernel: PREEMPT SMP
Oct 22 21:45:05 kefk kernel: Modules linked in: nls_cp437 lp parport_pc ub
hidp hci_usb snd_seq_midi snd_emu10k1_synth snd_emux_synth snd_seq_virmidi
snd_seq_midi_emul nvidia tun md5 ipv6 rfcomm l2cap bluetooth snd_seq_oss
snd_seq_midi_event snd_seq snd_pcm_oss snd_mixer_oss snd_emu10k1 snd_rawmidi
snd_seq_device snd_ac97_codec snd_pcm snd_timer snd_page_alloc snd_util_mem
snd_hwdep snd soundcore ipt_REJECT iptable_filter ip_tables loop nls_utf8
ide_cd i2c_dev w83
781d i2c_sensor i2c_isa i2c_i801 isofs zlib_inflate e1000 ppa parport ehci_hcd
usblp uhci_hcd genrtc
Oct 22 21:45:05 kefk kernel: CPU: 1
Oct 22 21:45:05 kefk kernel: EIP: 0060:[<c01862cf>] Tainted: P VLI
Oct 22 21:45:05 kefk kernel: EFLAGS: 00010246 (2.6.9-mm1)
Oct 22 21:45:05 kefk kernel: EIP is at sysfs_remove_dir+0x1d/0xef
Oct 22 21:45:05 kefk kernel: eax: cf85c308 ebx: cf85c308 ecx: c18ff480
edx: c1000000
Oct 22 21:45:05 kefk kernel: esi: edce7c00 edi: 00000000 ebp: 00000246
esp: c1bace20
Oct 22 21:45:05 kefk kernel: ds: 007b es: 007b ss: 0068
Oct 22 21:45:05 kefk kernel: Process khubd (pid: 125, threadinfo=c1bac000
task=c1baba40)
Oct 22 21:45:05 kefk kernel: Stack: 00000000 cf85c308 edce7c00 00000001
00000246 c01f2087 cf85c308 c01f2097
Oct 22 21:45:05 kefk kernel: cca37180 c01849fc 00000000 edce7c00
00000000 00000246 f8c48ff1 dc3ac848
Oct 22 21:45:05 kefk kernel: 0000003c 00000003 cca37294 f74ff02c
cca37180 cca37280 f8c4b220 c86ad000
Oct 22 21:45:05 kefk kernel: Call Trace:
Oct 22 21:45:05 kefk kernel: [<c01f2087>] kobject_del+0x14/0x1c
Oct 22 21:45:05 kefk kernel: [<c01f2097>] kobject_unregister+0x8/0x10
Oct 22 21:45:05 kefk kernel: [<c01849fc>] del_gendisk+0x1d/0xd5
Oct 22 21:45:05 kefk kernel: [<f8c48ff1>] ub_disconnect+0x11e/0x171 [ub]
Oct 22 21:45:05 kefk kernel: [<c0298f95>] usb_unbind_interface+0x5e/0x60
Oct 22 21:45:05 kefk kernel: [<c0243431>] device_release_driver+0x56/0x58
Oct 22 21:45:05 kefk kernel: [<c0243637>] bus_remove_device+0x53/0x90
Oct 22 21:45:05 kefk kernel: [<c0242752>] device_del+0x54/0x91
Oct 22 21:45:05 kefk kernel: [<c02a0ac3>] usb_disable_device+0xda/0x147
Oct 22 21:45:05 kefk kernel: [<c029b7ab>] usb_disconnect+0xab/0x198
Oct 22 21:45:05 kefk kernel: [<c029ca61>] hub_port_connect_change+0x2ce/0x47b
Oct 22 21:45:05 kefk kernel: [<c029cee2>] hub_events+0x2d4/0x4ac
Oct 22 21:45:05 kefk kernel: [<c029d0ef>] hub_thread+0x35/0x10e
Oct 22 21:45:05 kefk kernel: [<c0115155>] finish_task_switch+0x3b/0x87
Oct 22 21:45:05 kefk kernel: [<c012d9ad>] autoremove_wake_function+0x0/0x43
Oct 22 21:45:05 kefk kernel: [<c0103ca6>] ret_from_fork+0x6/0x14
Oct 22 21:45:05 kefk kernel: [<c012d9ad>] autoremove_wake_function+0x0/0x43
Oct 22 21:45:05 kefk kernel: [<c029d0ba>] hub_thread+0x0/0x10e
Oct 22 21:45:05 kefk kernel: [<c0102025>] kernel_thread_helper+0x5/0xb
Oct 22 21:45:05 kefk kernel: Code: 02 4c 32 c0 e9 4d ff ff ff e9 23 ff ff ff
55 57 56 53 83 ec 04 8b 78 30 85 ff 74 0d 8b 07 85 c0 0f 84 ca 00 00 00 f0 ff
07 85 ff <8b> 57 50 0f 84 b4 00 00 00 8b 47 10 8d 48 78 f0 ff 48 78 0f 88
After this, usb stack is unable to detect other usb devices insertions.
system: P IV 2.8 HT, smp/t+preempt, i875p (abit ic7g) 1Gb ram.
flash key: usb 2.0 flash drive, 512 MB
I can provide more details/testing if needed, config.gz attached.
--
Fabio Coatti http://members.ferrara.linux.it/cova
Ferrara Linux Users Group http://ferrara.linux.it
GnuPG fp:9765 A5B6 6843 17BC A646 BE8C FA56 373A 5374 C703
Old SysOps never die... they simply forget their password.
On Fri, 22 Oct 2004 20:45:18 -0700, Andrew Morton <[email protected]> wrote:
> looks like a ub.c problem.
Yes. At least partially.
> Date: Fri, 22 Oct 2004 21:59:20 +0200
> From: Fabio Coatti <[email protected]>
> Oct 22 21:40:05 kefk kernel: ub 5-3:1.0: usb_probe_interface - got id
> Oct 22 21:40:05 kefk kernel: uba: device 6 capacity nsec 50 bsize 512
> Oct 22 21:40:05 kefk kernel: uba: made changed
> Oct 22 21:40:05 kefk kernel: uba: device 6 capacity nsec 1024000 bsize 512
> Oct 22 21:40:05 kefk kernel: uba: device 6 capacity nsec 1024000 bsize 512
> Oct 22 21:40:05 kefk kernel: uba: uba1
> Oct 22 21:40:05 kefk kernel: uba: uba1
> Oct 22 21:40:05 kefk kernel: kobject_register failed for uba1 (-17)
> Oct 22 21:40:05 kefk kernel: [<c01f1f77>] kobject_register+0x51/0x5f
This looks like a race, but isn't. What actually happens is that the ub
returns a device changed indication from check_media_changed when the
device is connected. In such case, do_open will make another attempt
to read partitions. I discussed it with Al and he opined that no block
device should ever return a changed indication before the first open
has completed. If it cannot, it should refuse the open.
This only happens to devices which refuse to come online easily. Therefore,
I was going to fold a fix into a patch to add START STOP UNIT command.
It is not written yet.
The other side of this, the oops, is something for Viro/James/Axboe
to check out. It's entirely on their side. But of course, if ub quits
tripping the double registration condition, the problem of buggy
error paths in the block layer becomes moot. I'll work on it as soon
as possible.
-- Pete