Post by Petr VandrovecPost by Petr Vandrovecdoes your box hang, or is it just vmware process that is hung?
Just the "vmware" process that hangs only. It just got stuck, and
even kill -9 doesn't free it.
I've noticed that my box here at work has this change too, and I do
not see any hang - neither in kernel, or in GUI startup, nor in test
open("/proc/bus/usb/devices", O_RDWR) = 3
poll([{fd=3, events=POLLIN}], 1, 5000) = 1 ([{fd=3, revents=POLLIN}])
poll([{fd=3, events=POLLIN}], 1, 5000) = 0 (Timeout)
exit_group(0) = ?
petr-dev3:/tmp# uname -a
Linux petr-dev3 2.6.33-64-05079-g6517b45-dirty #51 SMP PREEMPT Thu
Mar 4 20:29:55 PST 2010 x86_64 GNU/Linux
Here's mine ...
open("/proc/bus/usb/devices", O_RDONLY) = 65
fcntl(65, F_GETFL) = 0x8000 (flags
O_RDONLY|O_LARGEFILE)
fstat(65, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x7f85396c8000
lseek(65, 0, SEEK_CUR) = 0
read(65,
Again in my previous email, on my box, "cat
/proc/bus/usb/devices" hangs as well. You sure you've commit
554f76962d3a6eb5110415f1591aca83f96a84ae
on yours?
Well, I hope. Disassembly of usbcore says that I have
mutex_lock(&usbfs_mutex) in usbfs_conn_disc_event, so that checkin
1cc10: 55 push %rbp
1cc11: 48 89 e5 mov %rsp,%rbp
1cc14: e8 00 00 00 00 callq 1cc19
<usbfs_conn_disc_event+0x9>
1cc15: R_X86_64_PC32 mcount+0xfffffffffffffffc
1cc19: 31 f6 xor %esi,%esi
1cc1b: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
1cc1e: R_X86_64_32S usbfs_mutex
1cc22: e8 00 00 00 00 callq 1cc27
<usbfs_conn_disc_event+0x17>
1cc23: R_X86_64_PC32
mutex_lock_nested+0xfffffffffffffffc
1cc27: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
1cc2a: R_X86_64_32S usbfs_mutex
1cc2e: ff 05 00 00 00 00 incl 0x0(%rip) #
1cc34 <usbfs_conn_disc_event+0x24>
1cc30: R_X86_64_PC32 .bss+0x9a4
1cc34: e8 00 00 00 00 callq 1cc39
<usbfs_conn_disc_event+0x29>
1cc35: R_X86_64_PC32
mutex_unlock+0xfffffffffffffffc
1cc39: 31 c9 xor %ecx,%ecx
1cc3b: ba 01 00 00 00 mov $0x1,%edx
1cc40: be 03 00 00 00 mov $0x3,%esi
1cc45: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
1cc48: R_X86_64_32S .data+0x1d00
1cc4c: e8 00 00 00 00 callq 1cc51
<usbfs_conn_disc_event+0x41>
1cc4d: R_X86_64_PC32
__wake_up+0xfffffffffffffffc
1cc51: c9 leaveq
1cc52: c3 retq
One thing is that I brought my only USB device home, so currently I
petr-dev3:/usr/src/git/linux-2.6# cat /proc/bus/usb/devices
T: Bus=02 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 3
B: Alloc= 0/900 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0001 Rev= 2.06
S: Manufacturer=Linux 2.6.33-64-05079-g6517b45-dirty ohci_hcd
S: Product=OHCI Host Controller
S: SerialNumber=0000:03:00.1
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 2 Ivl=255ms
T: Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 3
B: Alloc= 0/900 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0001 Rev= 2.06
S: Manufacturer=Linux 2.6.33-64-05079-g6517b45-dirty ohci_hcd
S: Product=OHCI Host Controller
S: SerialNumber=0000:03:00.0
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 2 Ivl=255ms
petr-dev3:/usr/src/git/linux-2.6#
I'll try upgrading my box at home. Maybe that one will hang.
I did not have issues with bringing VMware GUI with
64096c17417380d8a472d096645f4cbc9406c987 as tip of Linus's tree (which
is a believe the latest published), but got the following traces when
yanked USB keyboard out:
[ 1784.954389] usb 5-1: USB disconnect, address 2
[ 1784.954394] usb 5-1.3: USB disconnect, address 3
[ 1920.558046] INFO: task khubd:27 blocked for more than 120 seconds.
[ 1920.558051] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1920.558054] khubd D 0000000000000202 0 27 2 0x00000000
[ 1920.558060] ffff88011ba29960 0000000000000046 ffff88000260eec0 ffff88011ba20000
[ 1920.558067] ffff88011ba28000 ffff88011ba29fd8 ffff88011ba29fd8 ffff88011ba20000
[ 1920.558073] ffff88011ba29fd8 0000000000013d80 0000000000013d80 0000000000013d80
[ 1920.558079] Call Trace:
[ 1920.558088] [<ffffffff81478591>] __mutex_lock_common+0x1a1/0x4a0
[ 1920.558094] [<ffffffff8136f922>] ? usbfs_conn_disc_event+0x12/0x40
[ 1920.558099] [<ffffffff8107eb7d>] ? trace_hardirqs_on+0xd/0x10
[ 1920.558103] [<ffffffff8136f922>] ? usbfs_conn_disc_event+0x12/0x40
[ 1920.558107] [<ffffffff8147896e>] mutex_lock_nested+0x3e/0x50
[ 1920.558111] [<ffffffff8136f922>] usbfs_conn_disc_event+0x12/0x40
[ 1920.558115] [<ffffffff81371184>] usbfs_notify+0xa4/0x240
[ 1920.558119] [<ffffffff8147e007>] notifier_call_chain+0x47/0x90
[ 1920.558124] [<ffffffff8106f495>] __blocking_notifier_call_chain+0x55/0x80
[ 1920.558128] [<ffffffff8106f4d1>] blocking_notifier_call_chain+0x11/0x20
[ 1920.558132] [<ffffffff8136e7be>] usb_notify_remove_device+0x2e/0x50
[ 1920.558135] [<ffffffff8136e8a1>] generic_disconnect+0x11/0x30
[ 1920.558140] [<ffffffff81365db9>] usb_unbind_device+0x29/0x50
[ 1920.558145] [<ffffffff81303830>] __device_release_driver+0x70/0xe0
[ 1920.558149] [<ffffffff81303998>] device_release_driver+0x28/0x40
[ 1920.558153] [<ffffffff813029fc>] bus_remove_device+0xac/0xe0
[ 1920.558157] [<ffffffff81300d67>] device_del+0x127/0x1a0
[ 1920.558161] [<ffffffff8135bf2c>] usb_disconnect+0xec/0x160
[ 1920.558165] [<ffffffff8135bef7>] usb_disconnect+0xb7/0x160
[ 1920.558169] [<ffffffff8135c6ee>] hub_port_connect_change+0x8e/0x9f0
[ 1920.558172] [<ffffffff814783e9>] ? mutex_unlock+0x9/0x10
[ 1920.558176] [<ffffffff8135e263>] hub_events+0x3c3/0x580
[ 1920.558180] [<ffffffff8147a3cd>] ? _raw_spin_unlock_irqrestore+0x5d/0x70
[ 1920.558184] [<ffffffff8135e475>] hub_thread+0x55/0x190
[ 1920.558189] [<ffffffff810695a0>] ? autoremove_wake_function+0x0/0x40
[ 1920.558193] [<ffffffff8135e420>] ? hub_thread+0x0/0x190
[ 1920.558197] [<ffffffff8106908e>] kthread+0x8e/0xa0
[ 1920.558202] [<ffffffff81003dd4>] kernel_thread_helper+0x4/0x10
[ 1920.558206] [<ffffffff8147ab40>] ? restore_args+0x0/0x30
[ 1920.558210] [<ffffffff81069000>] ? kthread+0x0/0xa0
[ 1920.558213] [<ffffffff81003dd0>] ? kernel_thread_helper+0x0/0x10
[ 1920.558216] INFO: lockdep is turned off.
[ 1920.558254] INFO: task vmware-usbarbit:8039 blocked for more than 120 seconds.
[ 1920.558256] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1920.558259] vmware-usbarb D 0000000000000202 0 8039 1 0x00000080
[ 1920.558264] ffff8800cf7099a8 0000000000000046 ffff8800cf709928 ffff8800c5f22010
[ 1920.558270] ffff8800cf708000 ffff8800cf709fd8 ffff8800cf709fd8 ffff8800c5f22010
[ 1920.558276] ffff8800cf709fd8 0000000000013d80 0000000000013d80 0000000000013d80
[ 1920.558281] Call Trace:
[ 1920.558286] [<ffffffff81478591>] __mutex_lock_common+0x1a1/0x4a0
[ 1920.558290] [<ffffffff8136f97f>] ? usb_device_poll+0x2f/0x170
[ 1920.558293] [<ffffffff8136f97f>] ? usb_device_poll+0x2f/0x170
[ 1920.558297] [<ffffffff8106cfd0>] ? hrtimer_wakeup+0x0/0x30
[ 1920.558301] [<ffffffff8147896e>] mutex_lock_nested+0x3e/0x50
[ 1920.558305] [<ffffffff8136f97f>] usb_device_poll+0x2f/0x170
[ 1920.558309] [<ffffffff8112e104>] ? poll_schedule_timeout+0x44/0x60
[ 1920.558313] [<ffffffff8112e22b>] do_poll+0x10b/0x2b0
[ 1920.558317] [<ffffffff8112ef0e>] do_sys_poll+0x16e/0x230
[ 1920.558320] [<ffffffff8112e490>] ? __pollwait+0x0/0xf0
[ 1920.558324] [<ffffffff8112e580>] ? pollwake+0x0/0x60
[ 1920.558327] [<ffffffff8112e580>] ? pollwake+0x0/0x60
[ 1920.558331] [<ffffffff8112e580>] ? pollwake+0x0/0x60
[ 1920.558335] [<ffffffff81127bdc>] ? path_put+0x2c/0x40
[ 1920.558339] [<ffffffff81129854>] ? link_path_walk+0x424/0xc60
[ 1920.558343] [<ffffffff811272b5>] ? path_init+0xb5/0x1d0
[ 1920.558347] [<ffffffff81138bb4>] ? mntput_no_expire+0x24/0xf0
[ 1920.558351] [<ffffffff81114315>] ? kmem_cache_free+0xd5/0x140
[ 1920.558356] [<ffffffff8107ea09>] ? trace_hardirqs_on_caller+0x29/0x190
[ 1920.558360] [<ffffffff8107eb7d>] ? trace_hardirqs_on+0xd/0x10
[ 1920.558363] [<ffffffff81127400>] ? putname+0x30/0x50
[ 1920.558367] [<ffffffff81127400>] ? putname+0x30/0x50
[ 1920.558371] [<ffffffff8112afad>] ? user_path_at+0x5d/0xa0
[ 1920.558375] [<ffffffff81121817>] ? vfs_fstatat+0x37/0x70
[ 1920.558380] [<ffffffff81074029>] ? ktime_get_ts+0xa9/0xe0
[ 1920.558383] [<ffffffff8112e090>] ? poll_select_set_timeout+0x70/0xa0
[ 1920.558387] [<ffffffff8112f1b7>] sys_poll+0x77/0x110
[ 1920.558391] [<ffffffff81002fab>] system_call_fastpath+0x16/0x1b
[ 1920.558394] INFO: lockdep is turned off.
--
Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/