Messages in this thread | | | Subject | Re: drm_vm.c:drm_mmap: possible circular locking dependency detected | From | (Eric W. Biederman) | Date | Sun, 03 Jan 2010 02:57:15 -0800 |
| |
Dmitry Torokhov <dmitry.torokhov@gmail.com> writes:
> On Sun, Jan 03, 2010 at 09:32:06AM +0900, Tejun Heo wrote: >> On 01/03/2010 06:49 AM, Eric W. Biederman wrote: >> >> > For the moment I have generated a patch that does the lockdep >> > annotations, and I have found that a simple: >> > >> > find /sys -type f | xargs cat {} > /dev/null >> > >> > trivially generates lockdep warnings. In particular: >> >> (cc'ing Dmitry, Hi!) > > Hi Tejun! ;) > >> >> > [ 165.049042] >> > [ 165.049044] ======================================================= >> > [ 165.052761] [ INFO: possible circular locking dependency detected ] >> > [ 165.052761] 2.6.33-rc2x86_64 #3 >> > [ 165.052761] ------------------------------------------------------- >> > [ 165.052761] cat/5026 is trying to acquire lock: >> > [ 165.052761] (&serio->drv_mutex){+.+.+.}, at: [<ffffffff8132ecaa>] atkbd_attr_show_helper+0x28/0x6e >> > [ 165.052761] >> > [ 165.052761] but task is already holding lock: >> > [ 165.089443] (s_active){++++.+}, at: [<ffffffff810e84dd>] sysfs_get_active_two+0x2c/0x43 >> > [ 165.089443] >> > [ 165.089443] which lock already depends on the new lock. >> > [ 165.089443] >> > [ 165.089443] >> > [ 165.089443] the existing dependency chain (in reverse order) is: >> > [ 165.089443] >> > [ 165.089443] -> #1 (s_active){++++.+}: >> > [ 165.089443] [<ffffffff81054956>] validate_chain+0xa25/0xd1d >> > [ 165.089443] [<ffffffff810553d3>] __lock_acquire+0x785/0x7dc >> > [ 165.089443] [<ffffffff81056112>] lock_acquire+0x5a/0x74 >> > [ 165.089443] [<ffffffff810e8202>] sysfs_addrm_finish+0xba/0x125 >> > [ 165.089443] [<ffffffff810e68b0>] sysfs_hash_and_remove+0x4f/0x6b >> > [ 165.089443] [<ffffffff810e94cf>] remove_files+0x1f/0x2c >> > [ 165.089443] [<ffffffff810e9561>] sysfs_remove_group+0x85/0xb4 >> > [ 165.089443] [<ffffffff81331f0f>] psmouse_disconnect+0x33/0x147 >> > [ 165.089443] [<ffffffff8132687b>] serio_disconnect_driver+0x2d/0x3a >> > [ 165.089443] [<ffffffff81326898>] serio_driver_remove+0x10/0x14 >> > [ 165.089443] [<ffffffff812077f0>] __device_release_driver+0x67/0xb0 >> > [ 165.089443] [<ffffffff81207857>] device_release_driver+0x1e/0x2b >> > [ 165.089443] [<ffffffff81326e68>] serio_disconnect_port+0x60/0x69 >> > [ 165.089443] [<ffffffff8132757a>] serio_thread+0x170/0x34a >> > [ 165.089443] [<ffffffff810470e7>] kthread+0x7d/0x85 >> > [ 165.089443] [<ffffffff81002cd4>] kernel_thread_helper+0x4/0x10 >> > [ 165.089443] >> > [ 165.089443] -> #0 (&serio->drv_mutex){+.+.+.}: >> > [ 165.089443] [<ffffffff81054642>] validate_chain+0x711/0xd1d >> > [ 165.089443] [<ffffffff810553d3>] __lock_acquire+0x785/0x7dc >> > [ 165.089443] [<ffffffff81056112>] lock_acquire+0x5a/0x74 >> > [ 165.089443] [<ffffffff814378ed>] mutex_lock_interruptible_nested+0x4a/0x307 >> > [ 165.089443] [<ffffffff8132ecaa>] atkbd_attr_show_helper+0x28/0x6e >> > [ 165.089443] [<ffffffff8132ed81>] atkbd_do_show_extra+0x13/0x15 >> > [ 165.089443] [<ffffffff812049b6>] dev_attr_show+0x20/0x43 >> > [ 165.089443] [<ffffffff810e71db>] sysfs_read_file+0xba/0x145 >> > [ 165.089443] [<ffffffff8109f507>] vfs_read+0xab/0x147 >> > [ 165.089443] [<ffffffff8109f85c>] sys_read+0x47/0x70 >> > [ 165.089443] [<ffffffff81001f2b>] system_call_fastpath+0x16/0x1b >> > [ 165.089443] >> > [ 165.089443] other info that might help us debug this: >> > [ 165.089443] >> > [ 165.089443] 3 locks held by cat/5026: >> > [ 165.089443] #0: (&buffer->mutex){+.+.+.}, at: [<ffffffff810e715a>] sysfs_read_file+0x39/0x145 >> > [ 165.089443] #1: (s_active){++++.+}, at: [<ffffffff810e84d0>] sysfs_get_active_two+0x1f/0x43 >> > [ 165.089443] #2: (s_active){++++.+}, at: [<ffffffff810e84dd>] sysfs_get_active_two+0x2c/0x43 >> > [ 165.089443] >> > [ 165.089443] stack backtrace: >> > [ 165.089443] Pid: 5026, comm: cat Not tainted 2.6.33-rc2x86_64 #3 >> > [ 165.089443] Call Trace: >> > [ 165.089443] [<ffffffff810538f3>] print_circular_bug+0xb3/0xc1 >> > [ 165.089443] [<ffffffff81054642>] validate_chain+0x711/0xd1d >> > [ 165.089443] [<ffffffff81052fb6>] ? trace_hardirqs_on_caller+0x10b/0x12f >> > [ 165.089443] [<ffffffff810553d3>] __lock_acquire+0x785/0x7dc >> > [ 165.089443] [<ffffffff8132ecaa>] ? atkbd_attr_show_helper+0x28/0x6e >> > [ 165.089443] [<ffffffff81056112>] lock_acquire+0x5a/0x74 >> > [ 165.089443] [<ffffffff8132ecaa>] ? atkbd_attr_show_helper+0x28/0x6e >> > [ 165.089443] [<ffffffff814378ed>] mutex_lock_interruptible_nested+0x4a/0x307 >> > [ 165.089443] [<ffffffff8132ecaa>] ? atkbd_attr_show_helper+0x28/0x6e >> > [ 165.089443] [<ffffffff8132ee41>] ? atkbd_show_extra+0x0/0x28 >> > [ 165.089443] [<ffffffff8132ecaa>] atkbd_attr_show_helper+0x28/0x6e >> > [ 165.089443] [<ffffffff8132ed81>] atkbd_do_show_extra+0x13/0x15 >> > [ 165.089443] [<ffffffff812049b6>] dev_attr_show+0x20/0x43 >> > [ 165.089443] [<ffffffff810e71db>] sysfs_read_file+0xba/0x145 >> > [ 165.089443] [<ffffffff8109f507>] vfs_read+0xab/0x147 >> > [ 165.089443] [<ffffffff8109f85c>] sys_read+0x47/0x70 >> > [ 165.089443] [<ffffffff81001f2b>] system_call_fastpath+0x16/0x1b >> > >> > Suggestions on how to sort out this other set of issues are welcome. >> >> Ummm... read of an input sysfs node can trigger > > Read? I checked and I do not see where read would cause disconnect. > Also, disconnect only involves unbinding driver from the port, not the > destruction of the port itself (children may be destroyed but they have > different locks). > >> serio_disconnect_port() under serio->drv_mutex, which unfortunately >> would need to wait for completion of in-progress sysfs ops thus >> creating possibility for AB-BA deadlock. > > I think that we are dealing with different drv->mutex instances here. > >> Dmitry, is it possible to >> make serio_disconnect_port() asynchronous from the sysfs ops (ie. put >> it in a work or something)? > > I am not sure it is needed. Also in the trace presented > serio_disconnect_port() is called from kseriod which certainly does not > access sysfs... > > Overall I am not concerned about lockdep bitching about serio because it > still bitches if you simply reload psmouse on a box with Synaptics with a > pass-through port even though there are nested annotations and it is > silent first time around.
This is a new lockdep annotation, and looking into it this appears to be a true possible deadlock in the serio/sysfs interactions.
We have serio_pin_driver() called from all of the sysfs attributes which does: mutex_lock(&serio->drv_mutex);
We have serio_disconnect_driver() called on an unplug which does: mutex_lock(&serio->drv_mutex);
The deadlock potential is if someone reads say the psmouse rate sysfs file while the mouse is being unplugged. There is a race such that we can have:
sysfs_read_file() fill_read_buffer() sysfs_get_active_two() psmouse_attr_show_helper() serio_pin_driver() serio_disconnect_driver() mutex_lock(&serio->drv_mutex); <-----------------> mutex_lock(&serio_drv_mutex); psmouse_disconnect() sysfs_remove_group(... psmouse_attr_group); .... sysfs_deactivate(); wait_for_completion();
So it is unlikely but possible to deadlock by accessing a serio attribute of a serio device that is being removed.
What to do about it is another question. It has just recently come to my attention that we have more events like this
> Out of curiosity, do yo uknow what caused psmouse disconnect and what > kind of mouse is in the box?
It is a simple ps2mouse connected through a kvm, and the kvm was not switched to the machine in question during the run.
I am trying to wrap my head around what to do with this sysfs_deactivate deadlock scenario, (other drivers also hold unfortunate locks over the removal of sysfs files, and it just happens that the ps2mouse case was the first one I reproduced), and it was interesting because I had not seen it before.
Eric
| |