Re: "BUG: held lock freed!" lock validator tripped by kswapd & xfs

["Stephen Pollei" <stephen.pollei@gmail.com>]

On 12/1/06, Mike Mattie <codermattie@gmail.com> wrote:

> In an attempt to debug another kernel issue I turned on the lock validator and
> managed to generate this report.
>
> As a side note the first attempt to boot with the lock validator failed with
> a message indicating I had exceeded MAX_LOCK_DEPTH. To get this trace
> I patched sched.h: MAX_LOCK_DEPTH to 60.
>
> Dec  1 08:35:41 reforged [ 3052.513931] =========================
> Dec  1 08:35:41 reforged [ 3052.513937] [ BUG: held lock freed! ]
> Dec  1 08:35:41 reforged [ 3052.513939] -------------------------
> Dec  1 08:35:41 reforged [ 3052.513943] kswapd0/183 is freeing memory
> c3458000-c3458fff, with a lock still held there! Dec  1 08:35:41
> reforged [ 3052.513947]  (&(&ip->i_iolock)->mr_lock){....}, at:
> [<c0222289>] xfs_ilock+0x20/0x75 Dec  1 08:35:41 reforged
> [ 3052.513959] 28 locks held by kswapd0/183: Dec  1 08:35:41 reforged
> [ 3052.513961]  #0:  (&(&ip->i_iolock)->mr_lock){....}, at:
> [<c0222289>] xfs_ilock+0x20/0x75 Dec  1 08:35:41 reforged
> [ 3052.513968]  #1:  (&(&ip->i_lock)->mr_lock){....}, at: [<c02222bb>]
> xfs_ilock+0x52/0x75 Dec  1 08:35:41 reforged [ 3052.513975]

seems to alternate between same two locks. But both c0222289 and
c02222bb are not between the page(oxfff=4095 or about 4k) which kswapd
is trying to get rid of.
I think this trace is on crack somehow.

> [ 3052.514136] stack backtrace: Dec  1 08:35:41 reforged
> [ 3052.514139]  [<c0103cb9>] show_trace+0x16/0x19 Dec  1 08:35:41
> reforged [ 3052.514146]  [<c01040f7>] dump_stack+0x1a/0x1f Dec  1
> 08:35:41 reforged [ 3052.514150]  [<c012be74>]
> debug_check_no_locks_freed+0xe0/0xff Dec  1 08:35:41 reforged
> [ 3052.514159]  [<c014122d>] free_hot_cold_page+0x96/0x109 Dec  1
> 08:35:41 reforged [ 3052.514166]  [<c01412bc>] __pagevec_free+0x1c/0x27
> Dec  1 08:35:41 reforged [ 3052.514170]  [<c01435dc>]
> __pagevec_release_nonlru+0x65/0x71 Dec  1 08:35:41 reforged
> [ 3052.514176]  [<c0144702>] shrink_inactive_list+0x4b1/0x722 Dec  1
> 08:35:41 reforged [ 3052.514181]  [<c0144a2d>] shrink_zone+0xba/0xd9
> Dec  1 08:35:41 reforged [ 3052.514185]  [<c0144e9e>]
> kswapd+0x26a/0x361 Dec  1 08:35:41 reforged [ 3052.514189]
> [<c012742b>] kthread+0xb0/0xe1 Dec  1 08:35:41 reforged [ 3052.514192]
> [<c0101005>] kernel_thread_helper+0x5/0xb reforged log #

> Linux reforged 2.6.18.3 #4 PREEMPT Fri Dec 1 06:15:05 PST 2006 i686 AMD Athlon(tm) XP 3000+ AuthenticAMD GNU/Linux

I know you are running preempt on up machine. I'd try running 2.6.18.4
with a small patch like this and see if you can't cause it to recrash
for you. print_freed_lock_bug uses printk which in theory might be
causing a preempt .

diff -urp linux-2.6.18.4/include/linux/sched.h linux-debug/include/linux/sched.h
--- linux-2.6.18.4/include/linux/sched.h        2006-11-29
11:28:40.000000000 -0800
+++ linux-debug/include/linux/sched.h   2006-12-01 13:25:23.000000000 -0800
@@ -936,7 +936,7 @@ struct task_struct {
       int softirq_context;
#endif
#ifdef CONFIG_LOCKDEP
-# define MAX_LOCK_DEPTH 30UL
+# define MAX_LOCK_DEPTH (60UL)
       u64 curr_chain_key;
       int lockdep_depth;
       struct held_lock held_locks[MAX_LOCK_DEPTH];
diff -urp linux-2.6.18.4/kernel/lockdep.c linux-debug/kernel/lockdep.c
--- linux-2.6.18.4/kernel/lockdep.c     2006-11-29 11:28:40.000000000 -0800
+++ linux-debug/kernel/lockdep.c        2006-12-01 14:22:14.000000000 -0800
@@ -2608,6 +2608,7 @@ void debug_check_no_locks_freed(const vo
               return;

       local_irq_save(flags);
+       preempt_disable();
       for (i = 0; i < curr->lockdep_depth; i++) {
               hlock = curr->held_locks + i;

@@ -2621,6 +2622,7 @@ void debug_check_no_locks_freed(const vo
               print_freed_lock_bug(curr, mem_from, mem_to, hlock);
               break;
       }
+       preempt_enable();
       local_irq_restore(flags);
}


--
http://dmoz.org/profiles/pollei.html
http://sourceforge.net/users/stephen_pollei/
http://www.orkut.com/Profile.aspx?uid=2455954990164098214
http://stephen_pollei.home.comcast.net/
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/