[patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[Arjan van de Ven]

[-- Attachment #1: Type: text/plain, Size: 2212 bytes --]

Subject: Add the end-of-trace marker and the module list to WARN_ON()
From: Arjan van de Ven <arjan@linux.intel.com>
CC: Ingo Molnar <mingo@elte.hu>
CC: Andrew Morton <akpm@linux-foundation.org>
CC: Olof Johansson <olof@lixom.net>

Unlike oopses, WARN_ON() currently doesn't print the loaded modules list.
This makes it harder to take action on certain bug reports. For example,
recently there were a set of WARN_ON()s reported in the mac80211 stack,
which were just signaling a driver bug. It takes then anther round trip
to the bug reporter (if he responds at all) to find out which driver
is at fault.

Another issue is that, unlike oopses, WARN_ON() doesn't currently printk
the helpful "cut here" line, nor the "end of trace" marker.
Now that WARN_ON() is out of line, the size increase due to this is
minimal and it's worth adding.

Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>

---
  kernel/panic.c |   16 ++++++++++++----
  1 file changed, 12 insertions(+), 4 deletions(-)

Index: linux-2.6.24-rc6/kernel/panic.c
===================================================================
--- linux-2.6.24-rc6.orig/kernel/panic.c
+++ linux-2.6.24-rc6/kernel/panic.c
@@ -281,6 +281,13 @@ static int init_oops_id(void)
  }
  late_initcall(init_oops_id);

+static void print_oops_end_marker(void)
+{
+	init_oops_id();
+	printk(KERN_WARNING "---[ end trace %016llx ]---\n",
+		(unsigned long long)oops_id);
+}
+
  /*
   * Called when the architecture exits its oops handler, after printing
   * everything.
@@ -288,9 +295,7 @@ late_initcall(init_oops_id);
  void oops_exit(void)
  {
  	do_oops_enter_exit();
-	init_oops_id();
-	printk(KERN_WARNING "---[ end trace %016llx ]---\n",
-		(unsigned long long)oops_id);
+	print_oops_end_marker();
  }


@@ -298,11 +303,14 @@ void warn_on_slowpath(const char *file,
  {
  	char function[KSYM_SYMBOL_LEN];
  	unsigned long caller = (unsigned long) __builtin_return_address(0);
-
  	sprint_symbol(function, caller);
+
+	printk(KERN_WARNING "------------[ cut here ]------------\n");
  	printk(KERN_WARNING "WARNING: at %s:%d %s()\n", file,
  		line, function);
+	print_modules();
  	dump_stack();
+	print_oops_end_marker();
  }
  EXPORT_SYMBOL(warn_on_slowpath);


[-- Attachment #2: enhance-warnon-output.patch --]
[-- Type: text/x-patch, Size: 2197 bytes --]

Subject: Add the end-of-trace marker and the module list to WARN_ON()
From: Arjan van de Ven <arjan@linux.intel.com>
CC: Ingo Molnar <mingo@elte.hu>
CC: Andrew Morton <akpm@linux-foundation.org>
CC: Olof Johansson <olof@lixom.net>

Unlike oopses, WARN_ON() currently does't print the loaded modules list.
This makes it harder to take action on certain bug reports. For example,
recently there were a set of WARN_ON()s reported in the mac80211 stack,
which were just signalling a driver bug. It takes then anther round trip
to the bug reporter (if he responds at all) to find out which driver
is at fault.

Another issue is that, unlike oopses, WARN_ON() doesn't currently printk
the helpful "cut here" line, nor the "end of trace" marker.
Now that WARN_ON() is out of line, the size increase due to this is
minimal and it's worth adding.

Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>

---
 kernel/panic.c |   16 ++++++++++++----
 1 file changed, 12 insertions(+), 4 deletions(-)

Index: linux-2.6.24-rc6/kernel/panic.c
===================================================================
--- linux-2.6.24-rc6.orig/kernel/panic.c
+++ linux-2.6.24-rc6/kernel/panic.c
@@ -281,6 +281,13 @@ static int init_oops_id(void)
 }
 late_initcall(init_oops_id);
 
+static void print_oops_end_marker(void)
+{
+	init_oops_id();
+	printk(KERN_WARNING "---[ end trace %016llx ]---\n",
+		(unsigned long long)oops_id);
+}
+
 /*
  * Called when the architecture exits its oops handler, after printing
  * everything.
@@ -288,9 +295,7 @@ late_initcall(init_oops_id);
 void oops_exit(void)
 {
 	do_oops_enter_exit();
-	init_oops_id();
-	printk(KERN_WARNING "---[ end trace %016llx ]---\n",
-		(unsigned long long)oops_id);
+	print_oops_end_marker();
 }
 
 
@@ -298,11 +303,14 @@ void warn_on_slowpath(const char *file, 
 {
 	char function[KSYM_SYMBOL_LEN];
 	unsigned long caller = (unsigned long) __builtin_return_address(0);
-
 	sprint_symbol(function, caller);
+
+	printk(KERN_WARNING "------------[ cut here ]------------\n");
 	printk(KERN_WARNING "WARNING: at %s:%d %s()\n", file,
 		line, function);
+	print_modules();
 	dump_stack();
+	print_oops_end_marker();
 }
 EXPORT_SYMBOL(warn_on_slowpath);
 

Re: [patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[Ingo Molnar]

* Arjan van de Ven <arjan@linux.intel.com> wrote:

> +	printk(KERN_WARNING "------------[ cut here ]------------\n");
>  	printk(KERN_WARNING "WARNING: at %s:%d %s()\n", file,
>  		line, function);
> +	print_modules();
>  	dump_stack();
> +	print_oops_end_marker();

another thing: could we also put the marker into dump_stack(), and 
attach the marker to the Call Trace line?

	Ingo

Re: [patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[Arjan van de Ven]

Ingo Molnar wrote:
> * Arjan van de Ven <arjan@linux.intel.com> wrote:
> 
>> +	printk(KERN_WARNING "------------[ cut here ]------------\n");
>>  	printk(KERN_WARNING "WARNING: at %s:%d %s()\n", file,
>>  		line, function);
>> +	print_modules();
>>  	dump_stack();
>> +	print_oops_end_marker();
> 
> another thing: could we also put the marker into dump_stack(), and 
> attach the marker to the Call Trace line?
> 

I have a preliminary patch for that already but I'm not happy with it yet;
I need to redo it properly. It's neither depending nor incremental to these
2 patches though..

Re: [patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[Ingo Molnar]

* Arjan van de Ven <arjan@linux.intel.com> wrote:

> Ingo Molnar wrote:
>> * Arjan van de Ven <arjan@linux.intel.com> wrote:
>>
>>> +	printk(KERN_WARNING "------------[ cut here ]------------\n");
>>>  	printk(KERN_WARNING "WARNING: at %s:%d %s()\n", file,
>>>  		line, function);
>>> +	print_modules();
>>>  	dump_stack();
>>> +	print_oops_end_marker();
>>
>> another thing: could we also put the marker into dump_stack(), and attach 
>> the marker to the Call Trace line?
>
> I have a preliminary patch for that already but I'm not happy with it 
> yet; I need to redo it properly. It's neither depending nor 
> incremental to these 2 patches though..

yeah, it was a sidenote - it should be separate to these two patches.

	Ingo

Re: [patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[Heiko Carstens]

On Thu, Jan 03, 2008 at 10:27:28PM +0100, Arjan van de Ven wrote:
>
> Another issue is that, unlike oopses, WARN_ON() doesn't currently printk
> the helpful "cut here" line, nor the "end of trace" marker.
> Now that WARN_ON() is out of line, the size increase due to this is
> minimal and it's worth adding.
>
> +static void print_oops_end_marker(void)
> +{
> +	init_oops_id();
> +	printk(KERN_WARNING "---[ end trace %016llx ]---\n",
> +		(unsigned long long)oops_id);
> +}

There is also lib/bug.c which prints the "cut here" line but not the
"end of trace" line. Also it prints whatever it prints with a different
printk level.
Quite a few architectures use lib/bug.c also for WARN_ONs.
Maybe all the code should be in one place so it doesn't diverge all the
time?

Re: [patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[Arjan van de Ven]

Heiko Carstens wrote:
> On Thu, Jan 03, 2008 at 10:27:28PM +0100, Arjan van de Ven wrote:
>> Another issue is that, unlike oopses, WARN_ON() doesn't currently printk
>> the helpful "cut here" line, nor the "end of trace" marker.
>> Now that WARN_ON() is out of line, the size increase due to this is
>> minimal and it's worth adding.
>>
>> +static void print_oops_end_marker(void)
>> +{
>> +	init_oops_id();
>> +	printk(KERN_WARNING "---[ end trace %016llx ]---\n",
>> +		(unsigned long long)oops_id);
>> +}
> 
> There is also lib/bug.c which prints the "cut here" line but not the
> "end of trace" line. 

it ends up printing the "end of trace" line as part of the oops_exit() call
 >

> Also it prints whatever it prints with a different
> printk level.

as it should.. WARN_ON()'s are warnings so get KERN_WARNING ;-)

> Quite a few architectures use lib/bug.c also for WARN_ONs.

is this still the case after Olof's patch?

> Maybe all the code should be in one place so it doesn't diverge all the
> time?

it's actually ok as is.. the core tracing code lives in panic.c; lib/bug.c is just a few helpers
for BUG().. for WARN_ON() there is a lot less to help

Re: [patch 2/2] Add the end-of-trace marker and the module list to WARN_ON()

[Heiko Carstens]

On Fri, Jan 04, 2008 at 06:50:42AM -0800, Arjan van de Ven wrote:
> Heiko Carstens wrote:
>> On Thu, Jan 03, 2008 at 10:27:28PM +0100, Arjan van de Ven wrote:
>>> Another issue is that, unlike oopses, WARN_ON() doesn't currently printk
>>> the helpful "cut here" line, nor the "end of trace" marker.
>>> Now that WARN_ON() is out of line, the size increase due to this is
>>> minimal and it's worth adding.
>>>
>>> +static void print_oops_end_marker(void)
>>> +{
>>> +	init_oops_id();
>>> +	printk(KERN_WARNING "---[ end trace %016llx ]---\n",
>>> +		(unsigned long long)oops_id);
>>> +}
>> There is also lib/bug.c which prints the "cut here" line but not the
>> "end of trace" line. 
>
> it ends up printing the "end of trace" line as part of the oops_exit() call

Not on architectures that implement WARN_ON() with the help of lib/bug.c and
an invalid opcode. Your out of line helper function doesn't get called there.

Instead the exception handler calls report_bug() which in turn prints the
warning message, then calls show_regs() and returns BUG_TRAP_TYPE_WARN.

Afterwards the instruction pointer is incremented and execution continues.

This is true for powerpc, avr32, sh, parisc and s390.

Your out of line changes don't have any effect on these architectures.
Dunno.. maybe you are aware of this. Just wanted to make sure we aren't
talking of totally different things.

>> Also it prints whatever it prints with a different
>> printk level.
>
> as it should.. WARN_ON()'s are warnings so get KERN_WARNING ;-)

Not on all architectures.. see above :)

>> Quite a few architectures use lib/bug.c also for WARN_ONs.
>
> is this still the case after Olof's patch?

Yes, of course. Also I like the WARN_ON() with exception semantics much more
since it gives the ability to print the register contents etc. So you get
much more debug informations.

>> Maybe all the code should be in one place so it doesn't diverge all the
>> time?
>
> it's actually ok as is.. the core tracing code lives in panic.c; lib/bug.c 
> is just a few helpers
> for BUG().. for WARN_ON() there is a lot less to help

Not really... lib/bug.c handles both if the architecture wants it. It just
needs to set BUGFLAG_WARNING in the bug table entries for warnings.