Re: [PATCH] timer: implement lockdep deadlock detection

[Johannes Berg]

On Mon, 2009-01-26 at 23:59 +0100, Johannes Berg wrote:
> This modifies the timer code in a way to allow lockdep to detect
> deadlocks resulting from a lock being taken in the timer function
> as well as around the del_timer_sync() call.
> 
> Validated with this module, otherwise bootup was clean.

Not having a proper stack trace in there is a little confusing:

[   81.547455] 
[   81.547457] =======================================================
[   81.547657] [ INFO: possible circular locking dependency detected ]
[   81.547759] 2.6.29-rc2-wl-11979-gc32422d-dirty #24
[   81.547857] -------------------------------------------------------
[   81.547956] rmmod/3857 is trying to acquire lock:
[   81.548055]  (&t){-+..}, at: [<ffffffff80252960>] del_timer_sync+0x0/0xa0
[   81.548303] 
[   81.548303] but task is already holding lock:
[   81.548491]  (&l){.+..}, at: [<ffffffffa11f9010>] e+0x10/0x30 [test]
[   81.548736] 
[   81.548736] which lock already depends on the new lock.
[   81.548737] 
[   81.549023] 
[   81.549023] the existing dependency chain (in reverse order) is:
[   81.549212] 
[   81.549213] -> #1 (&l){.+..}:
[   81.549544]        [<ffffffffffffffff>] 0xffffffffffffffff
[   81.549697] 
[   81.549697] -> #0 (&t){-+..}:
[   81.550028]        [<ffffffff802737b7>] check_prev_add+0x57/0x770
[   81.550178]        [<ffffffff802744d6>] validate_chain+0x606/0x6c0
[   81.550322]        [<ffffffff802749cf>] __lock_acquire+0x43f/0xa10
[   81.550471]        [<ffffffff80275031>] lock_acquire+0x91/0xc0
[   81.550619]        [<ffffffff8025299d>] del_timer_sync+0x3d/0xa0
[   81.550767]        [<ffffffffa11f901c>] e+0x1c/0x30 [test]
[   81.550911]        [<ffffffff80281d9b>] sys_delete_module+0x27b/0x2e0
[   81.551062]        [<ffffffff8020bd1b>] system_call_fastpath+0x16/0x1b
[   81.551213]        [<ffffffffffffffff>] 0xffffffffffffffff
[   81.551361] 
[   81.551361] other info that might help us debug this:
[   81.551362] 
[   81.551646] 1 lock held by rmmod/3857:
[   81.551743]  #0:  (&l){.+..}, at: [<ffffffffa11f9010>] e+0x10/0x30 [test]
[   81.552035] 
[   81.552035] stack backtrace:
[   81.552222] Pid: 3857, comm: rmmod Not tainted 2.6.29-rc2-wl-11979-gc32422d-dirty #24
[   81.552371] Call Trace:
[   81.552469]  [<ffffffff80273260>] print_circular_bug_tail+0xe0/0xf0
[   81.552571]  [<ffffffff802737b7>] check_prev_add+0x57/0x770
[   81.552672]  [<ffffffff802744d6>] validate_chain+0x606/0x6c0
[   81.552773]  [<ffffffff802749cf>] __lock_acquire+0x43f/0xa10
[   81.552876]  [<ffffffff8026fb04>] ? get_lock_stats+0x34/0x70
[   81.552979]  [<ffffffff8026fb04>] ? get_lock_stats+0x34/0x70
[   81.553080]  [<ffffffff80275031>] lock_acquire+0x91/0xc0
[   81.553181]  [<ffffffff80252960>] ? del_timer_sync+0x0/0xa0
[   81.553284]  [<ffffffff8025299d>] del_timer_sync+0x3d/0xa0
[   81.553383]  [<ffffffff80252960>] ? del_timer_sync+0x0/0xa0
[   81.553487]  [<ffffffffa11f901c>] e+0x1c/0x30 [test]
[   81.553588]  [<ffffffff80281d9b>] sys_delete_module+0x27b/0x2e0
[   81.553690]  [<ffffffff8020c76d>] ? retint_swapgs+0xe/0x13
[   81.553792]  [<ffffffff80272c52>] ? trace_hardirqs_on_caller+0x182/0x1e0
[   81.553895]  [<ffffffff8020bd1b>] system_call_fastpath+0x16/0x1b

Attachment: signature.asc
Description: This is a digitally signed message part