[PATCH 0/4] compact call trace

[PATCH 0/4] compact call trace

[Akinobu Mita]

These patches will:

- break the various custom oops-parsers which people have written themselves.
- use common call trace format on x86-64.
- change offset format from hexadecimal to decimal in print_symbol()
- delete symbolsize in call trace in print_symbol().
- print system_utsname.version in oops so that we can doing a
  double check that the oops is matching the vmlinux we're looking at.

Example output:

o Currently we get the following call trace
i386: [<f0ad4c51>] kjournald+0x18c/0x207 [jbd]
x86-64: <ffffffffa008ef6c>{:jbd:kjournald+1030}

o After applied these patches.
i386: [<f0ad4c51>] kjournald+396 [jbd]
x86-64: <ffffffffa008ef6c> kjournald+1030 [jbd]

[PATCH 1/4] makes print_symbol() return int

[Akinobu Mita]

Use print_symbol() to dump call trace on x86-64.

Signed-off-by: Akinobu Mita <mita@miraclelinux.com>
----

 traps.c |   29 +++++++----------------------
 1 files changed, 7 insertions(+), 22 deletions(-)

--- 2.6-git/arch/x86_64/kernel/traps.c.orig	2006-01-16 22:05:38.000000000 +0900
+++ 2.6-git/arch/x86_64/kernel/traps.c	2006-01-16 22:07:36.000000000 +0900
@@ -30,6 +30,7 @@
 #include <linux/moduleparam.h>
 #include <linux/nmi.h>
 #include <linux/kprobes.h>
+#include <linux/kallsyms.h> 
 
 #include <asm/system.h>
 #include <asm/uaccess.h>
@@ -92,30 +93,14 @@ static inline void conditional_sti(struc
 
 static int kstack_depth_to_print = 10;
 
-#ifdef CONFIG_KALLSYMS
-#include <linux/kallsyms.h> 
-int printk_address(unsigned long address)
-{ 
-	unsigned long offset = 0, symsize;
-	const char *symname;
-	char *modname;
-	char *delim = ":"; 
-	char namebuf[128];
-
-	symname = kallsyms_lookup(address, &symsize, &offset, &modname, namebuf); 
-	if (!symname) 
-		return printk("[<%016lx>]", address);
-	if (!modname) 
-		modname = delim = ""; 		
-        return printk("<%016lx>{%s%s%s%s%+ld}",
-		      address,delim,modname,delim,symname,offset); 
-} 
-#else
 int printk_address(unsigned long address)
 { 
-	return printk("[<%016lx>]", address);
-} 
-#endif
+	int len;
+
+	len = printk("<%016lx>", address);
+	len += print_symbol(" %s", address);
+	return len;
+}
 
 static unsigned long *in_exception_stack(unsigned cpu, unsigned long stack,
 					unsigned *usedp, const char **idp)

[PATCH 2/4] x86-64: Use print_symbol() to dump call trace

[Akinobu Mita]

Use print_symbol() to dump call trace on x86-64.

Signed-off-by: Akinobu Mita <mita@miraclelinux.com>
----

 traps.c |   29 +++++++----------------------
 1 files changed, 7 insertions(+), 22 deletions(-)

--- 2.6-git/arch/x86_64/kernel/traps.c.orig	2006-01-16 22:05:38.000000000 +0900
+++ 2.6-git/arch/x86_64/kernel/traps.c	2006-01-16 22:07:36.000000000 +0900
@@ -30,6 +30,7 @@
 #include <linux/moduleparam.h>
 #include <linux/nmi.h>
 #include <linux/kprobes.h>
+#include <linux/kallsyms.h> 
 
 #include <asm/system.h>
 #include <asm/uaccess.h>
@@ -92,30 +93,14 @@ static inline void conditional_sti(struc
 
 static int kstack_depth_to_print = 10;
 
-#ifdef CONFIG_KALLSYMS
-#include <linux/kallsyms.h> 
-int printk_address(unsigned long address)
-{ 
-	unsigned long offset = 0, symsize;
-	const char *symname;
-	char *modname;
-	char *delim = ":"; 
-	char namebuf[128];
-
-	symname = kallsyms_lookup(address, &symsize, &offset, &modname, namebuf); 
-	if (!symname) 
-		return printk("[<%016lx>]", address);
-	if (!modname) 
-		modname = delim = ""; 		
-        return printk("<%016lx>{%s%s%s%s%+ld}",
-		      address,delim,modname,delim,symname,offset); 
-} 
-#else
 int printk_address(unsigned long address)
 { 
-	return printk("[<%016lx>]", address);
-} 
-#endif
+	int len;
+
+	len = printk("<%016lx>", address);
+	len += print_symbol(" %s", address);
+	return len;
+}
 
 static unsigned long *in_exception_stack(unsigned cpu, unsigned long stack,
 					unsigned *usedp, const char **idp)

[PATCH 3/4] compact print_symbol() output

[Akinobu Mita]

- remove symbolsize field
- change offset format from hexadecimal to decimal

99.9% of the functions in my vmlinux are smaller than 10000 bytes.
Therefore call trace must be more compact.

Signed-off-by: Akinobu Mita <mita@miraclelinux.com>
----

 kallsyms.c |    7 +++----
 1 files changed, 3 insertions(+), 4 deletions(-)

--- 2.6-git/kernel/kallsyms.c.orig	2006-01-16 22:06:16.000000000 +0900
+++ 2.6-git/kernel/kallsyms.c	2006-01-16 22:09:52.000000000 +0900
@@ -237,7 +237,7 @@ int __print_symbol(const char *fmt, unsi
 	const char *name;
 	unsigned long offset, size;
 	char namebuf[KSYM_NAME_LEN+1];
-	char buffer[sizeof("%s+%#lx/%#lx [%s]") + KSYM_NAME_LEN +
+	char buffer[sizeof("%s+%ld [%s]") + KSYM_NAME_LEN +
 		    2*(BITS_PER_LONG*3/10) + MODULE_NAME_LEN + 1];
 
 	name = kallsyms_lookup(address, &size, &offset, &modname, namebuf);
@@ -246,10 +246,9 @@ int __print_symbol(const char *fmt, unsi
 		sprintf(buffer, "0x%lx", address);
 	else {
 		if (modname)
-			sprintf(buffer, "%s+%#lx/%#lx [%s]", name, offset,
-				size, modname);
+			sprintf(buffer, "%s+%ld [%s]", name, offset, modname);
 		else
-			sprintf(buffer, "%s+%#lx/%#lx", name, offset, size);
+			sprintf(buffer, "%s+%ld", name, offset);
 	}
 	return printk(fmt, buffer);
 }

Re: [PATCH 3/4] compact print_symbol() output

[Keith Owens]

Akinobu Mita (on Tue, 17 Jan 2006 19:15:55 +0900) wrote:
>- remove symbolsize field
>- change offset format from hexadecimal to decimal

That is silly.  Almost every binutils tool prints offsets in hex,
including objdump and gdb.  Printing the trace offset in decimal just
makes more work for users to convert back to decimal to match up with
all the other tools.

Re: [PATCH 3/4] compact print_symbol() output

[Jesper Juhl]

On 1/17/06, Keith Owens <kaos@ocs.com.au> wrote:
> Akinobu Mita (on Tue, 17 Jan 2006 19:15:55 +0900) wrote:
> >- remove symbolsize field
> >- change offset format from hexadecimal to decimal
>
> That is silly.  Almost every binutils tool prints offsets in hex,
> including objdump and gdb.  Printing the trace offset in decimal just
> makes more work for users to convert back to decimal to match up with
> all the other tools.
>
Agreed.
Also, hex output is shorter and often more natural for this type of data.

--
Jesper Juhl <jesper.juhl@gmail.com>
Don't top-post  http://www.catb.org/~esr/jargon/html/T/top-post.html
Plain text mails only, please      http://www.expita.com/nomime.html

Re: [PATCH 3/4] compact print_symbol() output

[Akinobu Mita]

On Tue, Jan 17, 2006 at 11:52:19AM +0100, Jesper Juhl wrote:
> On 1/17/06, Keith Owens <kaos@ocs.com.au> wrote:
> > Akinobu Mita (on Tue, 17 Jan 2006 19:15:55 +0900) wrote:
> > >- remove symbolsize field
> > >- change offset format from hexadecimal to decimal
> >
> > That is silly.  Almost every binutils tool prints offsets in hex,
> > including objdump and gdb.  Printing the trace offset in decimal just
> > makes more work for users to convert back to decimal to match up with
> > all the other tools.
> >
> Agreed.
> Also, hex output is shorter and often more natural for this type of data.
> 

In my vmlinux, 99.9% of the functions are smaller than 10000 bytes.

10000 == 0x2710
So. strlen("10000") == 5 < strlen("0x2710") == 6
Therefore call trace must be more compact.

Re: [PATCH 3/4] compact print_symbol() output

[Keith Owens]

Akinobu Mita (on Tue, 17 Jan 2006 19:58:27 +0900) wrote:
>On Tue, Jan 17, 2006 at 11:52:19AM +0100, Jesper Juhl wrote:
>> On 1/17/06, Keith Owens <kaos@ocs.com.au> wrote:
>> > Akinobu Mita (on Tue, 17 Jan 2006 19:15:55 +0900) wrote:
>> > >- remove symbolsize field
>> > >- change offset format from hexadecimal to decimal
>> >
>> > That is silly.  Almost every binutils tool prints offsets in hex,
>> > including objdump and gdb.  Printing the trace offset in decimal just
>> > makes more work for users to convert back to decimal to match up with
>> > all the other tools.
>> >
>> Agreed.
>> Also, hex output is shorter and often more natural for this type of data.
>> 
>
>In my vmlinux, 99.9% of the functions are smaller than 10000 bytes.
>
>10000 == 0x2710
>So. strlen("10000") == 5 < strlen("0x2710") == 6
>Therefore call trace must be more compact.

Which is irrelevant when your change makes more work for everybody who
reads the trace.

Re: [PATCH 3/4] compact print_symbol() output

[Akinobu Mita]

On Tue, Jan 17, 2006 at 09:34:03PM +1100, Keith Owens wrote:
> Akinobu Mita (on Tue, 17 Jan 2006 19:15:55 +0900) wrote:
> >- remove symbolsize field
> >- change offset format from hexadecimal to decimal
> 
> That is silly.  Almost every binutils tool prints offsets in hex,
> including objdump and gdb.  Printing the trace offset in decimal just
> makes more work for users to convert back to decimal to match up with
> all the other tools.

Currently call trace on x86-64 prints offset in decimal.
Do you think it is better to print offset in hex on x86-64 too?
But Andi Kleen said he likes compact call trace in the reply to
my first version of these patches.

And do you have any objection to remove symbolsize output in
print_symbol()? I can't find useful usage about symbolsize in
print_symbol() except to do a double check that the oops is
matching the vmlinux we're looking at. (so I made 4/4)
Do you know any useful usage about symbolsize?

Re: [PATCH 3/4] compact print_symbol() output

[Hugh Dickins]

On Tue, 17 Jan 2006, Akinobu Mita wrote:
> 
> And do you have any objection to remove symbolsize output in
> print_symbol()? I can't find useful usage about symbolsize in
> print_symbol() except to do a double check that the oops is
> matching the vmlinux we're looking at. (so I made 4/4)
> Do you know any useful usage about symbolsize?

I've often found symbolsize useful.  Not when looking at an oops
from my own machine.  But when looking at an oops posted on LKML,
from someone who most likely has a different .config and different
compiler, different optimization and different inlining from mine.
symbolsize is a good clue as to how close their kernel is to the
one I've got built on my machine, how likely guesses I make based
on mine will apply to theirs, and whereabouts in the function that
it oopsed.

Hugh

Re: [PATCH 3/4] compact print_symbol() output

[Andi Kleen]

On Tuesday 17 January 2006 16:01, Hugh Dickins wrote:

> I've often found symbolsize useful.  Not when looking at an oops
> from my own machine.  But when looking at an oops posted on LKML,
> from someone who most likely has a different .config and different
> compiler, different optimization and different inlining from mine.
> symbolsize is a good clue as to how close their kernel is to the
> one I've got built on my machine, how likely guesses I make based
> on mine will apply to theirs, and whereabouts in the function that
> it oopsed.

Yes that is why I want it too.

-Andi

[PATCH 4/4] i386: print system_utsname.version in oops

[Akinobu Mita]

print system_utsname.version in i386 oops to make it possible doing a
double check that the oops is matching the vmlinux we're looking at.

for example:
(2.6.15-git12) --> (2.6.15-git12 #1 SMP Tue Jan 17 13:59:15 JST 2006)

Signed-off-by: Akinobu Mita <mita@miraclelinux.com>
----
 traps.c |    5 +++--
 1 files changed, 3 insertions(+), 2 deletions(-)

--- 2.6-git/arch/i386/kernel/traps.c.orig	2006-01-17 12:45:41.000000000 +0900
+++ 2.6-git/arch/i386/kernel/traps.c	2006-01-17 12:49:35.000000000 +0900
@@ -239,9 +239,10 @@ void show_registers(struct pt_regs *regs
 	}
 	print_modules();
 	printk(KERN_EMERG "CPU:    %d\nEIP:    %04x:[<%08lx>]    %s VLI\n"
-			"EFLAGS: %08lx   (%s) \n",
+			"EFLAGS: %08lx   (%s %s) \n",
 		smp_processor_id(), 0xffff & regs->xcs, regs->eip,
-		print_tainted(), regs->eflags, system_utsname.release);
+		print_tainted(), regs->eflags, system_utsname.release,
+		system_utsname.version);
 	print_symbol(KERN_EMERG "EIP is at %s\n", regs->eip);
 	printk(KERN_EMERG "eax: %08lx   ebx: %08lx   ecx: %08lx   edx: %08lx\n",
 		regs->eax, regs->ebx, regs->ecx, regs->edx);

Re: [PATCH 0/4] compact call trace

[Arjan van de Ven]

On Tue, 2006-01-17 at 19:13 +0900, Akinobu Mita wrote:
> These patches will:
> 
> - break the various custom oops-parsers which people have written themselves.
> - use common call trace format on x86-64.
> - change offset format from hexadecimal to decimal in print_symbol()
> - delete symbolsize in call trace in print_symbol().
> - print system_utsname.version in oops so that we can doing a
>   double check that the oops is matching the vmlinux we're looking at.


at least then make the kallsyms lookup mark up the string somehow (say
by putting a * in front of it) if the EIP is outside the size of the
symbol; so that we can spot garbage better.

Re: [PATCH 0/4] compact call trace

[Keith Owens]

Arjan van de Ven (on Tue, 17 Jan 2006 11:31:27 +0100) wrote:
>On Tue, 2006-01-17 at 19:13 +0900, Akinobu Mita wrote:
>> These patches will:
>> 
>> - break the various custom oops-parsers which people have written themselves.
>> - use common call trace format on x86-64.
>> - change offset format from hexadecimal to decimal in print_symbol()
>> - delete symbolsize in call trace in print_symbol().
>> - print system_utsname.version in oops so that we can doing a
>>   double check that the oops is matching the vmlinux we're looking at.
>
>
>at least then make the kallsyms lookup mark up the string somehow (say
>by putting a * in front of it) if the EIP is outside the size of the
>symbol; so that we can spot garbage better.

There is no such thing as "outside the size of the symbol".  kallsyms
does not save symbol size, it is calculated as the difference between
this symbol and the next one in the table.  By definition, every size
is correct - as long as all symbols are in the table.

Some symbols are omitted from kallsyms, which makes the calculation of
"symbol size" wrong for some symbols, those symbols appear bigger than
they really are.  Printing the symbol size was done years ago as a hint
to the reader, it told them what the kernel thought the symbol size was
and gave them something to check against.  That was when there were
very few symbols in the kernel, so most size calculations were wrong.
Nowadays it is probably irrelevant.

Re: [PATCH 3/4] compact print_symbol() output

[Chuck Ebbert]

In-Reply-To: <200601171601.52995.ak@suse.de>

On Tue, 17 Jan 2006 at 16:01:52 +0100, Andi Kleen wrote:

> On Tuesday 17 January 2006 16:01, Hugh Dickins wrote:
> 
> > I've often found symbolsize useful.  Not when looking at an oops
> > from my own machine.  But when looking at an oops posted on LKML,
> > from someone who most likely has a different .config and different
> > compiler, different optimization and different inlining from mine.
> > symbolsize is a good clue as to how close their kernel is to the
> > one I've got built on my machine, how likely guesses I make based
> > on mine will apply to theirs, and whereabouts in the function that
> > it oopsed.
> 
> Yes that is why I want it too.

OK, how about this: remove the "0x" from the function size, i.e. print:

        kernel_symbol+0xd3/10e

instead of:

        kernel_symbol+0xd3/0x10e

This saves two characters per symbol and it should still be clear that
the second number is hexadecimal.

Does that break any tools?
-- 
Chuck

Re: [PATCH 3/4] compact print_symbol() output

[Keith Owens]

Chuck Ebbert (on Tue, 17 Jan 2006 22:05:27 -0500) wrote:
>In-Reply-To: <200601171601.52995.ak@suse.de>
>
>On Tue, 17 Jan 2006 at 16:01:52 +0100, Andi Kleen wrote:
>
>> On Tuesday 17 January 2006 16:01, Hugh Dickins wrote:
>> 
>> > I've often found symbolsize useful.  Not when looking at an oops
>> > from my own machine.  But when looking at an oops posted on LKML,
>> > from someone who most likely has a different .config and different
>> > compiler, different optimization and different inlining from mine.
>> > symbolsize is a good clue as to how close their kernel is to the
>> > one I've got built on my machine, how likely guesses I make based
>> > on mine will apply to theirs, and whereabouts in the function that
>> > it oopsed.
>> 
>> Yes that is why I want it too.
>
>OK, how about this: remove the "0x" from the function size, i.e. print:
>
>        kernel_symbol+0xd3/10e
>
>instead of:
>
>        kernel_symbol+0xd3/0x10e
>
>This saves two characters per symbol and it should still be clear that
>the second number is hexadecimal.
>
>Does that break any tools?

Not, just CONFUSE-A-HUMAN (incorporating AMAZE-A-VOLE LTD, STUN-A-STOAT
LTD, PUZZLE-A-PUMA LTD, STARTLE-A-THOMPSON'S GAZELLE LTD,
BEWILDEREBEEST INC, DISTRACT-A-BEE).  Yes, I need a life.

Re: [PATCH 3/4] compact print_symbol() output

[Valdis.Kletnieks]

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

On Tue, 17 Jan 2006 22:05:27 EST, Chuck Ebbert said:

> OK, how about this: remove the "0x" from the function size, i.e. print:
> 
>         kernel_symbol+0xd3/10e
> 
> instead of:
> 
>         kernel_symbol+0xd3/0x10e
> 
> This saves two characters per symbol and it should still be clear that
> the second number is hexadecimal.

Good.  Now repeat for a function that's 6 bytes shorter.

[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]

Re: [PATCH 3/4] compact print_symbol() output

[Chuck Ebbert]

In-Reply-To: <200601180325.k0I3P8tF008591@turing-police.cc.vt.edu>

On Tue, 17 Jan 2006 at 22:25:07 -0500, Valdis.Kletnieks wrote:

> On Tue, 17 Jan 2006 22:05:27 EST, Chuck Ebbert said:
> 
> > OK, how about this: remove the "0x" from the function size, i.e. print:
> > 
> >         kernel_symbol+0xd3/10e
> > 
> > instead of:
> > 
> >         kernel_symbol+0xd3/0x10e
> > 
> > This saves two characters per symbol and it should still be clear that
> > the second number is hexadecimal.
>
> Good.  Now repeat for a function that's 6 bytes shorter.

OK, I probably should have done that:

        kernel_symbol+0xd3/108

My point is that if the "numerator" is hex you should assume the
"denominator" is too.
-- 
Chuck
Currently reading: _Einstein's Bridge_ by John Cramer