lkml.org 
[lkml]   [2010]   [Jan]   [3]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    SubjectRe: drm_vm.c:drm_mmap: possible circular locking dependency detected
    From
    Date
    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


    \
     
     \ /
      Last update: 2010-01-03 12:09    [W:0.037 / U:34.108 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site