lkml.org 
[lkml]   [2011]   [Jul]   [20]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    SubjectRe: recursive locking: epoll.
    From
    Date
    On Fri, 2011-07-15 at 17:04 -0400, Dave Jones wrote:
    > We just had a Fedora user report this lockdep trace.

    0) Does this have a bugzilla.redhat.com number?

    > =============================================
    > [ INFO: possible recursive locking detected ]
    > 3.0-0.rc7.git0.1.fc16.i686 #1
    > ---------------------------------------------
    > systemd-logind/651 is trying to acquire lock:
    > (&ep->mtx){+.+.+.}, at: [<c05285f1>] ep_scan_ready_list+0x32/0x154
    >
    > but task is already holding lock:
    > (&ep->mtx){+.+.+.}, at: [<c0528a90>] sys_epoll_ctl+0x103/0x481
    >
    > other info that might help us debug this:
    > Possible unsafe locking scenario:
    >
    > CPU0
    > ----
    > lock(&ep->mtx);
    > lock(&ep->mtx);
    >
    > *** DEADLOCK ***
    >
    > May be due to missing lock nesting notation
    >
    > 2 locks held by systemd-logind/651:
    > #0: (epmutex){+.+.+.}, at: [<c0528a4b>] sys_epoll_ctl+0xbe/0x481
    > #1: (&ep->mtx){+.+.+.}, at: [<c0528a90>] sys_epoll_ctl+0x103/0x481
    >
    > stack backtrace:
    > Pid: 651, comm: systemd-logind Not tainted 3.0-0.rc7.git0.1.fc16.i686 #1
    > Call Trace:
    > [<c08490fe>] ? printk+0x2d/0x2f
    > [<c046b2ef>] __lock_acquire+0x811/0xb63
    > [<c0407c77>] ? sched_clock+0x8/0xb
    > [<c045d190>] ? sched_clock_local+0x10/0x18b
    > [<c05285f1>] ? ep_scan_ready_list+0x32/0x154
    > [<c046ba5e>] lock_acquire+0xad/0xe4
    > [<c05285f1>] ? ep_scan_ready_list+0x32/0x154
    > [<c08506bd>] __mutex_lock_common+0x49/0x2ee
    > [<c05285f1>] ? ep_scan_ready_list+0x32/0x154
    > [<c04332e6>] ? __might_sleep+0x29/0xfb
    > [<c046a912>] ? mark_lock+0x26/0x1f2
    > [<c0850a7c>] mutex_lock_nested+0x43/0x49
    > [<c05285f1>] ? ep_scan_ready_list+0x32/0x154
    > [<c05285f1>] ep_scan_ready_list+0x32/0x154
    > [<c05281cb>] ? ep_remove+0x9b/0x9b
    > [<c0528727>] ep_poll_readyevents_proc+0x14/0x16
    > [<c05283d6>] ep_call_nested.constprop.2+0x6d/0x9a
    > [<c0528713>] ? ep_scan_ready_list+0x154/0x154
    > [<c05284d2>] ep_eventpoll_poll+0x45/0x55
    > [<c0528b8c>] sys_epoll_ctl+0x1ff/0x481
    > [<c05282fb>] ? ep_send_events_proc+0xd5/0xd5
    > [<c08521ac>] syscall_call+0x7/0xb

    1) It seems I just ran into that deadlock too (on a Fedora Rawhide
    system, running a vanilla 3.0-0.rc7). I tried to capture it with a small
    digital camera, but using that camera for screenshots is apparently
    beyond my skills. (I could try capturing this message over a serial
    line, if needed.)

    2) Luckily, I also hit a related warning rebooting into v2.6.39, which I
    could just cut and paste from dmesg's output:

    =============================================
    [ INFO: possible recursive locking detected ]
    2.6.39-0.local9.fc16.i686 #1
    ---------------------------------------------
    systemd-logind/807 is trying to acquire lock:
    (&ep->mtx){+.+.+.}, at: [<c0524a05>] ep_scan_ready_list+0x32/0x154

    but task is already holding lock:
    (&ep->mtx){+.+.+.}, at: [<c0524ea4>] sys_epoll_ctl+0x103/0x481

    other info that might help us debug this:
    2 locks held by systemd-logind/807:
    #0: (epmutex){+.+.+.}, at: [<c0524e5f>] sys_epoll_ctl+0xbe/0x481
    #1: (&ep->mtx){+.+.+.}, at: [<c0524ea4>] sys_epoll_ctl+0x103/0x481

    stack backtrace:
    Pid: 807, comm: systemd-logind Not tainted 2.6.39-0.local9.fc16.i686 #1
    Call Trace:
    [<c080af85>] ? printk+0x2d/0x2f
    [<c04690b7>] __lock_acquire+0x78f/0xae1
    [<c040790c>] ? sched_clock+0x8/0xb
    [<c045b858>] ? sched_clock_local+0x10/0x18b
    [<c0524a05>] ? ep_scan_ready_list+0x32/0x154
    [<c046981e>] lock_acquire+0xbc/0xdc
    [<c0524a05>] ? ep_scan_ready_list+0x32/0x154
    [<c08127f3>] __mutex_lock_common+0x4a/0x2f0
    [<c0524a05>] ? ep_scan_ready_list+0x32/0x154
    [<c0432502>] ? __might_sleep+0x29/0xfb
    [<c0466a50>] ? trace_hardirqs_off+0xb/0xd
    [<c0812b4e>] mutex_lock_nested+0x39/0x3e
    [<c0524a05>] ? ep_scan_ready_list+0x32/0x154
    [<c0524a05>] ep_scan_ready_list+0x32/0x154
    [<c05245df>] ? ep_remove+0x9b/0x9b
    [<c0524b3b>] ep_poll_readyevents_proc+0x14/0x16
    [<c05247ea>] ep_call_nested.constprop.2+0x6d/0x9a
    [<c0524b27>] ? ep_scan_ready_list+0x154/0x154
    [<c05248e6>] ep_eventpoll_poll+0x45/0x55
    [<c0524fa0>] sys_epoll_ctl+0x1ff/0x481
    [<c052470f>] ? ep_send_events_proc+0xd5/0xd5
    [<c0819fdf>] sysenter_do_call+0x12/0x38

    3) Apparently this is something that is triggered by a brand new version
    of systemd (systemd-30-1.fc16.i686, compiled on July 13th, which I
    installed just yesterday, July 19th), as I do not recall seeing this
    before.

    4) Feel free to prod me for more information.


    Paul Bolle



    \
     
     \ /
      Last update: 2011-07-20 10:07    [W:0.044 / U:2.924 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site