[PATCH] let WARN_ON() output the condition

[PATCH] let WARN_ON() output the condition

[Jiri Kosina]

[PATCH] let WARN_ON() output the condition

It is possible, in some cases, that the output of WARN_ON() is ambiguous 
and can't be properly used to identify the exact condition which caused 
the warning to trigger. This happens whenever there is a macro that 
contains multiple WARN_ONs inside. Notable example is spin_lock_mutex(). 
If any of the two WARN_ONs trigger, we are not able to say which one was 
the cause (as we get only line number, which however belongs to the place 
where the macro was expanded).

This patch lets WARN_ON() to output also the condition and fixes the 
DEBUG_LOCKS_WARN_ON() macro to pass the condition properly to WARN_ON. The 
possible drawback could be when someone passes a condition which has 
sideeffects. Then it would be evaluated twice, instead of current one 
evaluation. On the other hand, when anyone passes expression with 
sideeffects to WARN_ON(), he is asking for problems anyway.

Patch against 2.6.19-rc6-mm2.

Signed-off-by: Jiri Kosina <jkosina@suse.cz>

--- 

 include/asm-generic/bug.h   |    4 ++--
 include/linux/debug_locks.h |    2 +-
 2 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/include/asm-generic/bug.h b/include/asm-generic/bug.h
index a06eecd..af7574e 100644
--- a/include/asm-generic/bug.h
+++ b/include/asm-generic/bug.h
@@ -35,8 +35,8 @@ #ifndef HAVE_ARCH_WARN_ON
 #define WARN_ON(condition) ({						\
 	typeof(condition) __ret_warn_on = (condition);			\
 	if (unlikely(__ret_warn_on)) {					\
-		printk("WARNING at %s:%d %s()\n", __FILE__,	\
-			__LINE__, __FUNCTION__);			\
+		printk("WARNING (%s) at %s:%d %s()\n", #condition,	\
+			__FILE__,__LINE__, __FUNCTION__);		\
 		dump_stack();						\
 	}								\
 	unlikely(__ret_warn_on);					\
diff --git a/include/linux/debug_locks.h b/include/linux/debug_locks.h
index 952bee7..1c2b682 100644
--- a/include/linux/debug_locks.h
+++ b/include/linux/debug_locks.h
@@ -25,7 +25,7 @@ ({									\
 									\
 	if (unlikely(c)) {						\
 		if (debug_locks_off())					\
-			WARN_ON(1);					\
+			WARN_ON(c);					\
 		__ret = 1;						\
 	}								\
 	__ret;								\

Re: [PATCH] let WARN_ON() output the condition

[Andrew Morton]

On Wed, 6 Dec 2006 01:51:01 +0100 (CET)
Jiri Kosina <jkosina@suse.cz> wrote:

> [PATCH] let WARN_ON() output the condition
> 
> It is possible, in some cases, that the output of WARN_ON() is ambiguous 
> and can't be properly used to identify the exact condition which caused 
> the warning to trigger. This happens whenever there is a macro that 
> contains multiple WARN_ONs inside. Notable example is spin_lock_mutex(). 
> If any of the two WARN_ONs trigger, we are not able to say which one was 
> the cause (as we get only line number, which however belongs to the place 
> where the macro was expanded).
> 
> This patch lets WARN_ON() to output also the condition and fixes the 
> DEBUG_LOCKS_WARN_ON() macro to pass the condition properly to WARN_ON. The 
> possible drawback could be when someone passes a condition which has 
> sideeffects. Then it would be evaluated twice, instead of current one 
> evaluation. On the other hand, when anyone passes expression with 
> sideeffects to WARN_ON(), he is asking for problems anyway.
> 
> Patch against 2.6.19-rc6-mm2.
> 
> Signed-off-by: Jiri Kosina <jkosina@suse.cz>
> 
> --- 
> 
>  include/asm-generic/bug.h   |    4 ++--
>  include/linux/debug_locks.h |    2 +-
>  2 files changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/include/asm-generic/bug.h b/include/asm-generic/bug.h
> index a06eecd..af7574e 100644
> --- a/include/asm-generic/bug.h
> +++ b/include/asm-generic/bug.h
> @@ -35,8 +35,8 @@ #ifndef HAVE_ARCH_WARN_ON
>  #define WARN_ON(condition) ({						\
>  	typeof(condition) __ret_warn_on = (condition);			\
>  	if (unlikely(__ret_warn_on)) {					\
> -		printk("WARNING at %s:%d %s()\n", __FILE__,	\
> -			__LINE__, __FUNCTION__);			\
> +		printk("WARNING (%s) at %s:%d %s()\n", #condition,	\
> +			__FILE__,__LINE__, __FUNCTION__);		\
>  		dump_stack();						\
>  	}								\
>  	unlikely(__ret_warn_on);					\
> diff --git a/include/linux/debug_locks.h b/include/linux/debug_locks.h
> index 952bee7..1c2b682 100644
> --- a/include/linux/debug_locks.h
> +++ b/include/linux/debug_locks.h
> @@ -25,7 +25,7 @@ ({									\
>  									\
>  	if (unlikely(c)) {						\
>  		if (debug_locks_off())					\
> -			WARN_ON(1);					\
> +			WARN_ON(c);					\
>  		__ret = 1;						\
>  	}								\
>  	__ret;								\

Give me an additional 5k of text with distro config.  Is it worth it?

Re: [PATCH] let WARN_ON() output the condition

[Horst H. von Brand]

Andrew Morton <akpm@osdl.org> wrote:
> On Wed, 6 Dec 2006 01:51:01 +0100 (CET)
> Jiri Kosina <jkosina@suse.cz> wrote:
> 
> > [PATCH] let WARN_ON() output the condition
> > 
> > It is possible, in some cases, that the output of WARN_ON() is ambiguous 
> > and can't be properly used to identify the exact condition which caused 
> > the warning to trigger. This happens whenever there is a macro that 
> > contains multiple WARN_ONs inside. Notable example is spin_lock_mutex(). 
> > If any of the two WARN_ONs trigger, we are not able to say which one was 
> > the cause (as we get only line number, which however belongs to the place 
> > where the macro was expanded).
> > 
> > This patch lets WARN_ON() to output also the condition and fixes the 
> > DEBUG_LOCKS_WARN_ON() macro to pass the condition properly to WARN_ON. The 
> > possible drawback could be when someone passes a condition which has 
> > sideeffects. Then it would be evaluated twice, instead of current one 
> > evaluation. On the other hand, when anyone passes expression with 
> > sideeffects to WARN_ON(), he is asking for problems anyway.
> > 
> > Patch against 2.6.19-rc6-mm2.
> > 
> > Signed-off-by: Jiri Kosina <jkosina@suse.cz>
> > 
> > --- 
> > 
> >  include/asm-generic/bug.h   |    4 ++--
> >  include/linux/debug_locks.h |    2 +-
> >  2 files changed, 3 insertions(+), 3 deletions(-)
> > 
> > diff --git a/include/asm-generic/bug.h b/include/asm-generic/bug.h
> > index a06eecd..af7574e 100644
> > --- a/include/asm-generic/bug.h
> > +++ b/include/asm-generic/bug.h
> > @@ -35,8 +35,8 @@ #ifndef HAVE_ARCH_WARN_ON
> >  #define WARN_ON(condition) ({						\
> >  	typeof(condition) __ret_warn_on = (condition);			\
> >  	if (unlikely(__ret_warn_on)) {					\
> > -		printk("WARNING at %s:%d %s()\n", __FILE__,	\
> > -			__LINE__, __FUNCTION__);			\
> > +		printk("WARNING (%s) at %s:%d %s()\n", #condition,	\
> > +			__FILE__,__LINE__, __FUNCTION__);		\

			__FILE__, __LINE__, __FUNCTION__);

(missing space after "__FILE__,")
                     
> >  		dump_stack();						\
> >  	}								\
> >  	unlikely(__ret_warn_on);					\
> > diff --git a/include/linux/debug_locks.h b/include/linux/debug_locks.h
> > index 952bee7..1c2b682 100644
> > --- a/include/linux/debug_locks.h
> > +++ b/include/linux/debug_locks.h
> > @@ -25,7 +25,7 @@ ({									\
> >  									\
> >  	if (unlikely(c)) {						\
> >  		if (debug_locks_off())					\
> > -			WARN_ON(1);					\
> > +			WARN_ON(c);					\
> >  		__ret = 1;						\
> >  	}								\
> >  	__ret;								\


Why not just:

    WARN_ON(debug_locks_off())

here? Would give a more readable message too, IMHO.
-- 
Dr. Horst H. von Brand                   User #22616 counter.li.org
Departamento de Informatica                    Fono: +56 32 2654431
Universidad Tecnica Federico Santa Maria             +56 32 2654239
Casilla 110-V, Valparaiso, Chile               Fax:  +56 32 2797513

Re: [PATCH] let WARN_ON() output the condition

[Ingo Molnar]

* Horst H. von Brand <vonbrand@inf.utfsm.cl> wrote:

> Why not just:
> 
>     WARN_ON(debug_locks_off())
> 
> here? Would give a more readable message too, IMHO.

debug_locks_off() has a side-effect, and in general we dont like to put 
stuff with side-effects witin WARN_ON().

	Ingo

Re: [PATCH] let WARN_ON() output the condition

[Jaswinder Singh]

Hi,

I am playing with linux kernel but kernel dumps on WARN_ON , when I
commented WARN_ON in my code my kernel starts working but I get two
sideeffects :-

1. During Boot kernel Hangs sometimes in :-
Updating /etc/motd...done.
INIT: Entering runlevel: 3
<<hangs>>

2. Always Hangs in :-
cat /proc/interrupts
after showing interrupts
<<hangs>>

Are these side-effects of commenting WARN_ON.

Sometimes I also gets :-

<1>Unable to handle kernel NULL pointer dereference at virtual address 00000004
Unable to handle kernel NULL pointer dereference at virtual address 00000004
<1>pgd = c5810000
pgd = c5810000
<1>[00000004] *pgd=85844031[00000004] *pgd=85844031, *pte=00000000,
*pte=00000000, *ppte=00000000, *ppte=00000000

Internal error: Oops: 17 [#1]
Internal error: Oops: 17 [#1]
Modules linked in:Modules linked in:

CPU: 0
CPU: 0
PC is at dequeue_task+0xc/0x78
PC is at dequeue_task+0xc/0x78
LR is at deactivate_task+0x24/0x30
LR is at deactivate_task+0x24/0x30
pc : [<c0037264>]    lr : [<c003759c>]    Not tainted
sp : c545ddcc  ip : c545dddc  fp : c545ddd8
pc : [<c0037264>]    lr : [<c003759c>]    Not tainted
sp : c545ddcc  ip : c545dddc  fp : c545ddd8
r10: c68fd340  r9 : c02e04d4  r8 : c028ccf8
r10: c68fd340  r9 : c02e04d4  r8 : c028ccf8
r7 : c028ded8  r6 : c028ccf4  r5 : c545c000  r4 : c68fd340
r7 : c028ded8  r6 : c028ccf4  r5 : c545c000  r4 : c68fd340
r3 : 00000002  r2 : 00000000  r1 : 00000000  r0 : c68fd340
r3 : 00000002  r2 : 00000000  r1 : 00000000  r0 : c68fd340
Flags: NzcvFlags: Nzcv  IRQs on  FIQs on  Mode SVC_32  Segment user
  IRQs on  FIQs on  Mode SVC_32  Segment user
Control: 5317F  Table: 85810000  DAC: 00000015
Control: 5317F  Table: 85810000  DAC: 00000015
Process X (pid: 1107, stack limit = 0xc545c198)
Process X (pid: 1107, stack limit = 0xc545c198)
Stack: (0xc545ddcc to 0xc545e000)
Stack: (0xc545ddcc to 0xc545e000)

How to get rid of dequeue_task issue.

Thanks

Jaswinder Singh.

On 12/6/06, Ingo Molnar <mingo@elte.hu> wrote:
>
> * Horst H. von Brand <vonbrand@inf.utfsm.cl> wrote:
>
> > Why not just:
> >
> >     WARN_ON(debug_locks_off())
> >
> > here? Would give a more readable message too, IMHO.
>
> debug_locks_off() has a side-effect, and in general we dont like to put
> stuff with side-effects witin WARN_ON().
>
>        Ingo
> -
> 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/
>

Re: [PATCH] let WARN_ON() output the condition

[Jiri Kosina]

On Wed, 6 Dec 2006, Jaswinder Singh wrote:

> I am playing with linux kernel but kernel dumps on WARN_ON , when I 
> commented WARN_ON in my code my kernel starts working but I get two 
> sideeffects :-

Hi,

please, submit a proper bugreport, including all the needed data (see 
REPORTING-BUGS document in the kernel sources), namely kernel version, HW 
architecture, extra patches applied, configuration, loaded modules, etc.

Also, your issue is not related to this thread at all, could you please 
start a new one with more descriptive name, so there is a chance that 
someone responsible notices? This thread is about how WARN_ON is 
implemented, not about problems with certain modules triggering WARN_ON 
messages.

> Internal error: Oops: 17 [#1]
> Modules linked in:Modules linked in:
> CPU: 0
> CPU: 0
> PC is at dequeue_task+0xc/0x78
> PC is at dequeue_task+0xc/0x78
> LR is at deactivate_task+0x24/0x30
> LR is at deactivate_task+0x24/0x30
> pc : [<c0037264>]    lr : [<c003759c>]    Not tainted
> sp : c545ddcc  ip : c545dddc  fp : c545ddd8
> pc : [<c0037264>]    lr : [<c003759c>]    Not tainted
> sp : c545ddcc  ip : c545dddc  fp : c545ddd8
> r10: c68fd340  r9 : c02e04d4  r8 : c028ccf8
> r10: c68fd340  r9 : c02e04d4  r8 : c028ccf8
> r7 : c028ded8  r6 : c028ccf4  r5 : c545c000  r4 : c68fd340
> r7 : c028ded8  r6 : c028ccf4  r5 : c545c000  r4 : c68fd340
> r3 : 00000002  r2 : 00000000  r1 : 00000000  r0 : c68fd340
> r3 : 00000002  r2 : 00000000  r1 : 00000000  r0 : c68fd340
> Flags: NzcvFlags: Nzcv  IRQs on  FIQs on  Mode SVC_32  Segment user
>  IRQs on  FIQs on  Mode SVC_32  Segment user
> Control: 5317F  Table: 85810000  DAC: 00000015
> Control: 5317F  Table: 85810000  DAC: 00000015
> Process X (pid: 1107, stack limit = 0xc545c198)
> Process X (pid: 1107, stack limit = 0xc545c198)
> Stack: (0xc545ddcc to 0xc545e000)
> Stack: (0xc545ddcc to 0xc545e000)

BTW seems really strange. Do you really get all the lines output twice?

Thanks,

-- 
Jiri Kosina

Re: [PATCH] let WARN_ON() output the condition

[Ingo Molnar]

* Jiri Kosina <jkosina@suse.cz> wrote:

> [PATCH] let WARN_ON() output the condition
> 
> It is possible, in some cases, that the output of WARN_ON() is 
> ambiguous and can't be properly used to identify the exact condition 
> which caused the warning to trigger. This happens whenever there is a 
> macro that contains multiple WARN_ONs inside. Notable example is 
> spin_lock_mutex(). If any of the two WARN_ONs trigger, we are not able 
> to say which one was the cause (as we get only line number, which 
> however belongs to the place where the macro was expanded).

a WARN_ON() also triggers a stack dump, which should pinpoint the exact 
location. (especially if combined with kallsyms) For example:

posix_cpu_timer/13[CPU#1]: BUG in trace_stop_sched_switched at kernel/latency_trace.c:2142

Call Trace:
 [<ffffffff8020b272>] dump_trace+0xaf/0x3f4
 [<ffffffff8020b5f6>] show_trace+0x3f/0x5d
 [<ffffffff8020b8c1>] dump_stack+0x1a/0x1c
 [<ffffffff8022ef09>] __WARN_ON+0x65/0x80
 [<ffffffff80252c37>] trace_stop_sched_switched+0xad/0x30a
 [<ffffffff804ae810>] thread_return+0xa5/0x123
 [<ffffffff804aea15>] schedule+0xdd/0x101
 [<ffffffff8024298f>] posix_cpu_timers_thread+0x86/0xe5
 [<ffffffff80240c26>] kthread+0xd6/0x100
 [<ffffffff8020a938>] child_rip+0xa/0x12

here the "trace_stop_sched_switched+0xad/0x30a" is a perfect 
identification of the WARN_ON() code location - if there's any doubt 
about why the problem happened.

> This patch lets WARN_ON() to output also the condition and fixes the 
> DEBUG_LOCKS_WARN_ON() macro to pass the condition properly to WARN_ON. 
> The possible drawback could be when someone passes a condition which 
> has sideeffects. Then it would be evaluated twice, instead of current 
> one evaluation. On the other hand, when anyone passes expression with 
> sideeffects to WARN_ON(), he is asking for problems anyway.

side-effects happen regularly in WARN_ON()s and while they should be 
avoided, they are not noticed by the compiler and can cause nasty bugs 
if executed twice. Do we really need this change?

	Ingo

Re: [PATCH] let WARN_ON() output the condition

[Jiri Kosina]

On Wed, 6 Dec 2006, Ingo Molnar wrote:

> a WARN_ON() also triggers a stack dump, which should pinpoint the exact 
> location. (especially if combined with kallsyms) For example:

Actually, I was referring to something a little bit different. For example 
kernel/mutex.c:__mutex_lock_common() calls spin_lock_mutex() on line 132. 
spin_lock_mutex() contains

                DEBUG_LOCKS_WARN_ON(in_interrupt());    \
                local_irq_save(flags);                  \
                __raw_spin_lock(&(lock)->raw_lock);     \
                DEBUG_LOCKS_WARN_ON(l->magic != l);     \

When one of these two WARN_ONs trigger, we get only

	WARNING at kernel/mutex.c:132 __mutex_lock_common()

but it's indistuingishable which of the two WARN_ONs triggered. My patch 
turns this into

	WARNING (l->magic != l) at kernel/mutex.c:132 __mutex_lock_common()

> side-effects happen regularly in WARN_ON()s and while they should be 
> avoided, they are not noticed by the compiler and can cause nasty bugs 
> if executed twice. Do we really need this change?

I absolutely don't insist on it to be merged, besides this Andrew also 
pointed out non-trivial .text growth. I just cooked it up for myself when 
debugging some locking problems and that warning at kernel/mutex.c:132 
triggered, and I didn't know which one was the reason.

-- 
Jiri Kosina

Re: [PATCH] let WARN_ON() output the condition

[Ingo Molnar]

* Jiri Kosina <jikos@jikos.cz> wrote:

> On Wed, 6 Dec 2006, Ingo Molnar wrote:
> 
> > a WARN_ON() also triggers a stack dump, which should pinpoint the exact 
> > location. (especially if combined with kallsyms) For example:
> 
> Actually, I was referring to something a little bit different. For example 
> kernel/mutex.c:__mutex_lock_common() calls spin_lock_mutex() on line 132. 
> spin_lock_mutex() contains
> 
>                 DEBUG_LOCKS_WARN_ON(in_interrupt());    \
>                 local_irq_save(flags);                  \
>                 __raw_spin_lock(&(lock)->raw_lock);     \
>                 DEBUG_LOCKS_WARN_ON(l->magic != l);     \
> 
> When one of these two WARN_ONs trigger, we get only
> 
> 	WARNING at kernel/mutex.c:132 __mutex_lock_common()

no, that's not all we get - we should also get a stackdump. Are you not 
getting a stackdump perhaps?

but i agree with you in theory that your proposed output is better, but 
the side-effect issue is a killer i think. Could you try to rework it to 
not evaluate the condition twice and to make it dependent on 
CONFIG_DEBUG_BUGVERBOSE? You can avoid the evaluation side-effect issue 
by doing something like:

	int __c = (c);							\
                                                                        \
        if (unlikely(__c)) {                                            \
                if (debug_locks_off())                                  \
                        WARN_ON(__c);                                   \
                __ret = 1;                                              \

	Ingo

Re: [PATCH] let WARN_ON() output the condition

[Jiri Kosina]

On Wed, 6 Dec 2006, Ingo Molnar wrote:

> >                 DEBUG_LOCKS_WARN_ON(in_interrupt());    \
> >                 local_irq_save(flags);                  \
> >                 __raw_spin_lock(&(lock)->raw_lock);     \
> >                 DEBUG_LOCKS_WARN_ON(l->magic != l);     \
> > When one of these two WARN_ONs trigger, we get only
> > 	WARNING at kernel/mutex.c:132 __mutex_lock_common()
> no, that's not all we get - we should also get a stackdump. Are you not 
> getting a stackdump perhaps?

I am getting stackump, but I am perhaps just blind and don't see how to 
use it to distinguish the two WARN_ONs() conveniently, besides of 
disassembling the __mutex_lock_dommon and comparing it with offset in a 
stackdump. Well, not that it's not doable, but ...

> but i agree with you in theory that your proposed output is better, but 
> the side-effect issue is a killer i think. Could you try to rework it to 
> not evaluate the condition twice and to make it dependent on 
> CONFIG_DEBUG_BUGVERBOSE? You can avoid the evaluation side-effect issue 
> by doing something like:
> 	int __c = (c);							\
>                                                                         \
>         if (unlikely(__c)) {                                            \
>                 if (debug_locks_off())                                  \
>                         WARN_ON(__c);                                   \
>                 __ret = 1;                                              \
> 

Yep, making it dependent on CONFIG_DEBUG_BUGVERBOSE makes sense. Andrew, 
will you take such patch? (when I also fix the evaluating-twice issue).

Thanks,

-- 
Jiri Kosina

Re: [PATCH] let WARN_ON() output the condition

[Ingo Molnar]

* Jiri Kosina <jikos@jikos.cz> wrote:

> > but i agree with you in theory that your proposed output is better, but 
> > the side-effect issue is a killer i think. Could you try to rework it to 
> > not evaluate the condition twice and to make it dependent on 
> > CONFIG_DEBUG_BUGVERBOSE? You can avoid the evaluation side-effect issue 
> > by doing something like:
> > 	int __c = (c);							\
> >                                                                         \
> >         if (unlikely(__c)) {                                            \
> >                 if (debug_locks_off())                                  \
> >                         WARN_ON(__c);                                   \
> >                 __ret = 1;                                              \
> > 
> 
> Yep, making it dependent on CONFIG_DEBUG_BUGVERBOSE makes sense. 
> Andrew, will you take such patch? (when I also fix the 
> evaluating-twice issue).

i'll probably ack such a patch, it can be useful even when the line 
number is unique: if someone reports a WARN_ON() from an old kernel i 
dont have to dig up the exact source but can see it right from the 
condition what happened. Useful redundancy in bug output can be quite 
useful at times. Please post it and we'll see whether it's acceptable.

	Ingo

Re: [PATCH] let WARN_ON() output the condition

[Jiri Kosina]

On Wed, 6 Dec 2006, Ingo Molnar wrote:

> i'll probably ack such a patch, it can be useful even when the line 
> number is unique: if someone reports a WARN_ON() from an old kernel i 
> dont have to dig up the exact source but can see it right from the 
> condition what happened. Useful redundancy in bug output can be quite 
> useful at times. Please post it and we'll see whether it's acceptable.

OK, thanks, I will send it later today.

BTW I still don't see how to distinguish it easily ... for example:

WARNING at kernel/mutex.c:132 __mutex_lock_common()
 [<c0103d70>] dump_trace+0x68/0x1b5
 [<c0103ed5>] show_trace_log_lvl+0x18/0x2c
 [<c010445b>] show_trace+0xf/0x11
 [<c01044cd>] dump_stack+0x12/0x14
 [<c037523f>] __mutex_lock_slowpath+0xc6/0x261
 [<c0199c61>] create_dir+0x24/0x1ba
 [<c019a30b>] sysfs_create_dir+0x45/0x5f
 [<c01f302b>] kobject_add+0xd6/0x18d
 [<c01f31fb>] kobject_register+0x19/0x30
 [<c02e771a>] md_probe+0x11a/0x124
 [<c0267fa4>] kobj_lookup+0xe6/0x122
 [<c01ec12e>] get_gendisk+0xe/0x1b
 [<c018590e>] do_open+0x2e/0x298
 [<c0185d0f>] blkdev_open+0x25/0x4d
 [<c016451b>] __dentry_open+0xc3/0x17e
 [<c0164650>] nameidata_to_filp+0x24/0x33
 [<c0164691>] do_filp_open+0x32/0x39
 [<c01646da>] do_sys_open+0x42/0xbe
 [<c016478f>] sys_open+0x1c/0x1e
 [<c0102dbc>] syscall_call+0x7/0xb

How can you see immediately which one of the two WARN_ONs in 
spin_lock_mutex() triggered?

-- 
Jiri Kosina

Re: [PATCH] let WARN_ON() output the condition

[Ingo Molnar]

* Jiri Kosina <jikos@jikos.cz> wrote:

> On Wed, 6 Dec 2006, Ingo Molnar wrote:
> 
> > i'll probably ack such a patch, it can be useful even when the line 
> > number is unique: if someone reports a WARN_ON() from an old kernel i 
> > dont have to dig up the exact source but can see it right from the 
> > condition what happened. Useful redundancy in bug output can be quite 
> > useful at times. Please post it and we'll see whether it's acceptable.
> 
> OK, thanks, I will send it later today.
> 
> BTW I still don't see how to distinguish it easily ... for example:
> 
> WARNING at kernel/mutex.c:132 __mutex_lock_common()
>  [<c0103d70>] dump_trace+0x68/0x1b5
>  [<c0103ed5>] show_trace_log_lvl+0x18/0x2c
>  [<c010445b>] show_trace+0xf/0x11
>  [<c01044cd>] dump_stack+0x12/0x14
>  [<c037523f>] __mutex_lock_slowpath+0xc6/0x261
>  [<c0199c61>] create_dir+0x24/0x1ba
>  [<c019a30b>] sysfs_create_dir+0x45/0x5f
>  [<c01f302b>] kobject_add+0xd6/0x18d
>  [<c01f31fb>] kobject_register+0x19/0x30
>  [<c02e771a>] md_probe+0x11a/0x124
>  [<c0267fa4>] kobj_lookup+0xe6/0x122
>  [<c01ec12e>] get_gendisk+0xe/0x1b
>  [<c018590e>] do_open+0x2e/0x298
>  [<c0185d0f>] blkdev_open+0x25/0x4d
>  [<c016451b>] __dentry_open+0xc3/0x17e
>  [<c0164650>] nameidata_to_filp+0x24/0x33
>  [<c0164691>] do_filp_open+0x32/0x39
>  [<c01646da>] do_sys_open+0x42/0xbe
>  [<c016478f>] sys_open+0x1c/0x1e
>  [<c0102dbc>] syscall_call+0x7/0xb
> 
> How can you see immediately which one of the two WARN_ONs in 
> spin_lock_mutex() triggered?

yeah, i can tell that even without assembly or gdb, just from the 
offset:

>  [<c037523f>] __mutex_lock_slowpath+0xc6/0x261

there are 4 WARN_ON()s in __mutex_lock_slowpath(), distributed roughly 
equally. Which makes the above one the second out of the four 
WARN_ON()s, i.e.:

                DEBUG_LOCKS_WARN_ON(l->magic != l);     \

Did i get it right? (but then again i guess i've got an unfair advantage 
in interpreting locking related bug messages ;-)

but it can also be told semantically, it cannot be the in_interrupt() 
assert because this is clearly not IRQ context:

>  [<c037523f>] __mutex_lock_slowpath+0xc6/0x261
>  [<c0199c61>] create_dir+0x24/0x1ba
>  [<c019a30b>] sysfs_create_dir+0x45/0x5f

but in such cases i'd rather suggest the use of inline functions instead 
of macros and then it's a simple gdb lookup to figure out the call site. 
So, which clown added that macro to mutex-debug.h ... oh, never mind.

	Ingo

Re: [PATCH] let WARN_ON() output the condition

[Jan Engelhardt]

On Dec 6 2006 10:07, Ingo Molnar wrote:
>
>i'll probably ack such a patch, it can be useful even when the line 
>number is unique: if someone reports a WARN_ON() from an old kernel i 
>dont have to dig up the exact source but can see it right from the 
>condition what happened. Useful redundancy in bug output can be quite 
>useful at times. Please post it and we'll see whether it's acceptable.
>

Or just make it a compile-time decision, so those who do not want the 5k
overhead do not get it.


	-`J'
--