commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Jeff Chua]

Linux version v2.6.33-5399-gcc7889f with reiser3 and vmware-7.0.1

Starting vmware just hang even before displaying the main GUI. Reverting 
554f76962d3a6eb5110415f1591aca83f96a84ae solves the problem.

It seems vmware is trying to access the USB but this commit blocks it.

So, is this a vmware problem or shall this be reverted?


Thanks,
Jeff


commit 554f76962d3a6eb5110415f1591aca83f96a84ae
Author: Oliver Neukum <oliver@neukum.org>
Date:   Wed Jan 13 15:30:47 2010 +0100

     USB: Remove BKL from poll()

     Replace BKL with usbfs_mutex to protect a global counter
     and a per file data structure

     Signed-off-by: Oliver Neukum <oliver@neukum.org>
     Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>

diff --git a/drivers/usb/core/devices.c b/drivers/usb/core/devices.c
index 355dffc..175529f 100644
--- a/drivers/usb/core/devices.c
+++ b/drivers/usb/core/devices.c
@@ -118,6 +118,7 @@ static const char *format_endpt =
   */

  static DECLARE_WAIT_QUEUE_HEAD(deviceconndiscwq);
+/* guarded by usbfs_mutex */
  static unsigned int conndiscevcnt;

  /* this struct stores the poll state for <mountpoint>/devices pollers */
@@ -156,7 +157,9 @@ static const struct class_info clas_info[] =

  void usbfs_conn_disc_event(void)
  {
+	mutex_lock(&usbfs_mutex);
  	conndiscevcnt++;
+	mutex_unlock(&usbfs_mutex);
  	wake_up(&deviceconndiscwq);
  }

@@ -629,42 +632,29 @@ static ssize_t usb_device_read(struct file *file, char __user *buf,
  static unsigned int usb_device_poll(struct file *file,
  				    struct poll_table_struct *wait)
  {
-	struct usb_device_status *st = file->private_data;
+	struct usb_device_status *st;
  	unsigned int mask = 0;

-	lock_kernel();
+	mutex_lock(&usbfs_mutex);
+	st = file->private_data;
  	if (!st) {
  		st = kmalloc(sizeof(struct usb_device_status), GFP_KERNEL);
-
-		/* we may have dropped BKL -
-		 * need to check for having lost the race */
-		if (file->private_data) {
-			kfree(st);
-			st = file->private_data;
-			goto lost_race;
-		}
-		/* we haven't lost - check for allocation failure now */
  		if (!st) {
-			unlock_kernel();
+			mutex_unlock(&usbfs_mutex);
  			return POLLIN;
  		}

-		/*
-		 * need to prevent the module from being unloaded, since
-		 * proc_unregister does not call the release method and
-		 * we would have a memory leak
-		 */
  		st->lastev = conndiscevcnt;
  		file->private_data = st;
  		mask = POLLIN;
  	}
-lost_race:
+
  	if (file->f_mode & FMODE_READ)
  		poll_wait(file, &deviceconndiscwq, wait);
  	if (st->lastev != conndiscevcnt)
  		mask |= POLLIN;
  	st->lastev = conndiscevcnt;
-	unlock_kernel();
+	mutex_unlock(&usbfs_mutex);
  	return mask;
  }

Re: commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Linus Torvalds]

On Sat, 6 Mar 2010, Jeff Chua wrote:
> 
> Linux version v2.6.33-5399-gcc7889f with reiser3 and vmware-7.0.1
> 
> Starting vmware just hang even before displaying the main GUI. Reverting
> 554f76962d3a6eb5110415f1591aca83f96a84ae solves the problem.
> 
> It seems vmware is trying to access the USB but this commit blocks it.
> 
> So, is this a vmware problem or shall this be reverted?

It's almost certainly a deadlock through some path that wasn't tested.

Can you enable lockdep on that kernel when you run vmware, which should 
give us a nice callchain etc, and hopefully make it very obvious what goes 
on.

Reverting it is obviously an option, but with some more info maybe there's 
a better solution.

(It may be that the deadlock is obvious to Oliver/Greg even without any 
lockdep chains, of course, but still worth trying, I suspect)

		Linus

Re: commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Petr Vandrovec]

Linus Torvalds wrote:
> 
> On Sat, 6 Mar 2010, Jeff Chua wrote:
>> Linux version v2.6.33-5399-gcc7889f with reiser3 and vmware-7.0.1
>>
>> Starting vmware just hang even before displaying the main GUI. Reverting
>> 554f76962d3a6eb5110415f1591aca83f96a84ae solves the problem.
>>
>> It seems vmware is trying to access the USB but this commit blocks it.
>>
>> So, is this a vmware problem or shall this be reverted?

Hello,
    does your box hang, or is it just vmware process that is hung?  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 sample:

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

							Petr

[Removed Eli from CC.  He left.]

> 
> It's almost certainly a deadlock through some path that wasn't tested.
> 
> Can you enable lockdep on that kernel when you run vmware, which should 
> give us a nice callchain etc, and hopefully make it very obvious what goes 
> on.
> 
> Reverting it is obviously an option, but with some more info maybe there's 
> a better solution.
> 
> (It may be that the deadlock is obvious to Oliver/Greg even without any 
> lockdep chains, of course, but still worth trying, I suspect)
> 
> 		Linus

Re: commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Petr Vandrovec]

Jeff Chua wrote:
> 
> 
> On Sat, Mar 6, 2010 at 11:45 AM, Petr Vandrovec <petr@vmware.com 
> <mailto:petr@vmware.com>> wrote:
> 
>       does 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
>     sample:
> 
>     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 
should be in my tree:

000000000001cc10 <usbfs_conn_disc_event>:
    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 have 
none attached to the box:

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.
							Petr

Re: commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Oliver Neukum]

Am Samstag, 6. März 2010 06:22:48 schrieb Jeff Chua:
> It seems to hang trying to read from /proc/bus/usb/devices.
> 
> So, next I just try to "cat /proc/bus/usb/devices" and it hangs as well.
> 
> Reverting the commit makes "cat /proc/bus/usb/devices" works again.
> 
> Does this happen to me only?

As far as I can tell, yes. I cannot replicate it.

Please get me at least a sysrq-T trace.
There's no obvious place usb_device_read() takes usbfs_mutex.

	Regards
		Oliver

Re: commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Dmitry Torokhov]

On Fri, Mar 05, 2010 at 10:46:26PM -0800, Petr Vandrovec wrote:
> Jeff Chua wrote:
> >
> >
> >On Sat, Mar 6, 2010 at 11:45 AM, Petr Vandrovec <petr@vmware.com
> ><mailto:petr@vmware.com>> wrote:
> >
> >      does 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
> >    sample:
> >
> >    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
> should be in my tree:
> 
> 000000000001cc10 <usbfs_conn_disc_event>:
>    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
> have none attached to the box:
> 
> 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

Re: commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Oliver Neukum]

Am Samstag, 6. März 2010 10:33:07 schrieb Dmitry Torokhov:
> 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

Thanks, seems like a lock is taken twice.
Dmitry, can you test this patch, too?

	Regards
		Oliver

>From e58722a5fc0c00bceaea1f70d5024f6325ac3a6c Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oliver@neukum.org>
Date: Sat, 6 Mar 2010 12:09:41 +0100
Subject: [PATCH] usb: usbfs: Fix deadlock of khubd

The caller of usbfs_conn_disc_event() already holds usbfs_mutex.
Don't take it again.

Signed-off-by: Oliver Neukum <neukum@b1-systems.de>
---
 drivers/usb/core/devices.c |    3 +--
 1 files changed, 1 insertions(+), 2 deletions(-)

diff --git a/drivers/usb/core/devices.c b/drivers/usb/core/devices.c
index c83c975..08def6b 100644
--- a/drivers/usb/core/devices.c
+++ b/drivers/usb/core/devices.c
@@ -155,11 +155,10 @@ static const struct class_info clas_info[] =
 
 /*****************************************************************/
 
+/* the caller holds usbfs_mutex */
 void usbfs_conn_disc_event(void)
 {
-	mutex_lock(&usbfs_mutex);
 	conndiscevcnt++;
-	mutex_unlock(&usbfs_mutex);
 	wake_up(&deviceconndiscwq);
 }
 
-- 
1.6.4.2

Re: commit 554f76962d3a6eb5110415f1591aca83f96a84ae hangs USB for vmware 7.0.1

[Heinz Diehl]

On 06.03.2010, Oliver Neukum wrote:

> From: Oliver Neukum <oliver@neukum.org>
> Date: Sat, 6 Mar 2010 12:09:41 +0100
> Subject: [PATCH] usb: usbfs: Fix deadlock of khubd
>
> The caller of usbfs_conn_disc_event() already holds usbfs_mutex.
> Don't take it again.
>
> Signed-off-by: Oliver Neukum <neukum@b1-systems.de>
> ---
>  drivers/usb/core/devices.c |    3 +--
>  1 files changed, 1 insertions(+), 2 deletions(-)
>
> diff --git a/drivers/usb/core/devices.c b/drivers/usb/core/devices.c
> index c83c975..08def6b 100644
> --- a/drivers/usb/core/devices.c
> +++ b/drivers/usb/core/devices.c
> @@ -155,11 +155,10 @@ static const struct class_info clas_info[] =
>
>  /*****************************************************************/
>
> +/* the caller holds usbfs_mutex */
>  void usbfs_conn_disc_event(void)
>  {
> -     mutex_lock(&usbfs_mutex);
>       conndiscevcnt++;
> -     mutex_unlock(&usbfs_mutex);
>       wake_up(&deviceconndiscwq);
>  }

I had a bug on my system which occured when I connected an USB mp3
player more than once:

When plugged in the first time, the device worked as expected. After
pulling it, it didn't get recognized again when plugged it.
Only a reboot did help.  2.6.33 final is fine, 2.6.33-gitX isn't.

Your patch, applied to -git11, did fix this.

Thanks,
Heinz.