Improved ksymoops output

Improved ksymoops output

[Denis Vlasenko]

I was thinking of streamlining oops reports path.
Currently, people are expected to:
1) Run ksymoops
2) Figure out of function names where problems are.
   If one wants to look up source code of those functions,
   he is bound to do (lots of) grepping in source tree.
3) Figure out whom to email oops report.
   People _expected to_ look into MAINTAINERS file.

See that "_expected to_"? People frequently forget about it
(or even don't know). They mail to lkml only or worse, to Linus.
If maintainer isn't reading each and every lkml email, he can miss
oops report.

Running ksymoops is unavoidable, but other two steps can be automated,
and IMHO they should be.

It turned out to be trivially possible to fool ksymoops in taking System.map
where function names are accompanied with source file names and email
addresses of people willing to receive oopses. Emails are added by matching
regexp with filename. Let me show you how it looks like:

X             S C02AE060     8  2006   2005          2008       (NOTLB)
Call Trace: [<c0130e00>] [<c01459cf>] [<c0113ee7>] [<c0113e38>] [<c021049f>]
   [<c0145d05>] [<c0146002>] [<c010644e>] [<c011b432>] [<c011b7e3>] [<c01071ff>]

Normal ksymoops
===============
Call Trace: [<c0130e00>] [<c01459cf>] [<c0113ee7>] [<c0113e38>] [<c021049f>]
   [<c0145d05>] [<c0146002>] [<c010644e>] [<c011b432>] [<c011b7e3>] [<c01071ff>]
Warning (Oops_read): Code line not seen, dumping what data is available
Trace; c0130e00 <__get_free_pages+10/1c>
Trace; c01459cf <__pollwait+33/90>
Trace; c0113ee7 <schedule_timeout+4f/98>
Trace; c0113e38 <process_timeout+0/60>
Trace; c021049f <sock_poll+1f/24>
Trace; c0145d05 <do_select+209/214>
Trace; c0146002 <sys_select+2d2/620>
Trace; c010644e <restore_sigcontext+126/138>
Trace; c011b432 <sys_setitimer+76/150>
Trace; c011b7e3 <sys_gettimeofday+1b/17c>
Trace; c01071ff <system_call+33/38>

Ksymoops with file names and optionally regexp matched email addrs
==================================================================
Warning (compare_maps): ksyms_base symbol ... not found in System.map.  Ignoring ksyms_base entry
...<<tons of similar warnings>>...
Call Trace: [<c0130e00>] [<c01459cf>] [<c0113ee7>] [<c0113e38>] [<c021049f>]
   [<c0145d05>] [<c0146002>] [<c010644e>] [<c011b432>] [<c011b7e3>] [<c01071ff>]
Warning (Oops_read): Code line not seen, dumping what data is available
Trace; c0130e00 <__get_free_pages(mm/page_alloc.c)+10/1c>
Trace; c01459cf <__pollwait(fs/select.c:viro@math.psu.edu,tester3@host.org)+33/90>
Trace; c0113ee7 <schedule_timeout(kernel/sched.c)+4f/98>
Trace; c0113e38 <process_timeout(kernel/sched.c)+0/60>
Trace; c021049f <sock_poll(net/socket.c)+1f/24>
Trace; c0145d05 <do_select(fs/select.c:viro@math.psu.edu,tester3@host.org)+209/214>
Trace; c0146002 <sys_select(fs/select.c:viro@math.psu.edu,tester3@host.org)+2d2/620>
Trace; c010644e <restore_sigcontext(arch/i386/kernel/signal.c)+126/138>
Trace; c011b432 <sys_setitimer(kernel/itimer.c)+76/150>
Trace; c011b7e3 <sys_gettimeofday(kernel/time.c)+1b/17c>
Trace; c01071ff <system_call+33/38>
1044 warnings issued.  Results may not be reliable.

If you are willing to take a look, here are the scripts.
Usage: save files to kernel dir, then do:
# gen_func2file.map
# gen_System.map.annot >System.map.annot
# ksymoops -m System.map.annot <oops

email2pattern.map
=================
viro@math.psu.edu:^fs/[A-Za-z0-9]*.c$
neilb@cse.unsw.edu.au:fs/nfsd/.*
neilb@cse.unsw.edu.au:drivers/md/(md)|(raid)|(linear).*
tester@host.org:.*/mm/.*
tester2@host.org:.*usb.*
tester3@host.org:^fs/.*
tester4@host.org:.*ext2.*

gen_func2file.map
=================
#!/bin/sh
# Meant to be run in top lever kernel source dir
# after kernel has been built
#
# Makes list of the form:
# symbol1 object_file_pathname1
# symbol2 object_file_pathname2
# symbol3 object_file_pathname3
LIST=`find -name '*.c' | xargs`
> func2file.map
for a in $LIST; do
    #nm: get symbols from .o
    #grep: discard non-text symbols
    #awk: remove './', add .o pathname
    #cut: remove address and symbol type letter
    l=$((${#a}-2))
    b=${a:0:$l}
    if test -e "$b.o"; then
        nm "$b.o" \
	| grep '\( T \)\|\( t \)' \
	| awk "BEGIN { N=\" ${a:2:9999}\" } { print \$0,N }" \
	| cut -b12- \
	>> func2file.map
    fi
done

gen_System.map.annot
====================
#!/usr/bin/python
import string
import re
#
# Build func->file dictionary
#
f=open('func2file.map', 'r')
func2file={}
l=f.readline()
while l <> '':
    l=l[0:len(l)-1]
    t=string.split(l)
    func2file[t[0]]=t[1]
    l=f.readline()
#
# Read email:pattern list
#
f=open('email2pattern.map', 'r')
people=[]
l=f.readline()
while l <> '':
    l=l[0:len(l)-1]
    people.append(l)
    l=f.readline()
#
# Read System.map, add file names and email addresses
#
f=open('System.map', 'r')
l=f.readline()
while l <> '':
    l=l[0:len(l)-1]
    t=string.split(l)
    if func2file.has_key(t[2]):
	file=func2file[t[2]]
	l=l+'('+file
	el=''
	for p in people:
	    t=string.split(p,':')
	    email=t[0]
	    pattern=t[1]
            expr=re.compile(pattern)
	    if expr.match(file):
		el=el+','+email
	if el <> '':
	    l=l+':'+el[1:]
	l=l+')'
    print l
    l=f.readline()
--
vda

Re: Improved ksymoops output

[Roberto Nibali]

Hello,

I like the idea very much. As I have to maintain a kernel tree for 
various customers too, I think this could be a nice addition for the bug 
reports (seldom luckily) I sometimes get.

> gen_func2file.map
> =================

[snipped rest of the bash script]

This can be improved a little bit:

----------------------------------------------------------------
#!/bin/sh
# Meant to be run in top lever kernel source dir
# after kernel has been built
#
# Makes list of the form:
# symbol1 object_file_pathname1
# symbol2 object_file_pathname2
# symbol3 object_file_pathname3

 > func2file.map

find -name '*.c' | while read a; do
     #nm: get symbols from .o
     #grep: discard non-text symbols
     #awk: remove './', add .o pathname
     #cut: remove address and symbol type letter
     b=${a%.*}
     test -e "${b}.o" && {
         nm "${b}.o" \
         | grep '\( T \)\|\( t \)' \
         | awk "BEGIN { N=\" ${a:2}\" } { print \$0,N }" \
         | cut -b12- \
         >> func2file.map
     }
done
----------------------------------------------------------------

This script compared to yours does (it's nitpicking):
o run faster (5%) ;)
o should never have problems when one day there will be a lot of *.c
   files. In your approach LIST could someday not hold all entries
   anymore.
o simplifies the bash 'regexp' to snip away the '.c' and print the rest

I'm propably going to rewrite the python script in bash too, since I 
don't run python on my distro (and I do not intend to use 2.5.x anytime 
soon).

Best regards,
Roberto Nibali, ratz

Re: Improved ksymoops output

[Roberto Nibali]

Hi,

[reduced cc list, since I don't think the rest of the guys are 
interested in non-kernel related things]

> As already pointed out, format is horrendous, but prettier format
> requires much more serious hacking in ksymoops sources instead of my
> quick and very dirty tricks.

Yep, I see. After rethinking about this I have to agree with Russell. 
And I mean you still can't educate people to read FAQ's and manuals. 
Even with your output people that have no knowledge about this output 
will the things you mentioned as rationale. If one sees your inital oops 
where the hell does he get the information about calling your scripts 
without reading some document you must be providing. Well, and if he 
needs to read your docu he can as well read oops-tracing.txt. This is my 
little world, YMMV.

>>o run faster (5%) ;)
>>o should never have problems when one day there will be a lot of *.c
>>   files. In your approach LIST could someday not hold all entries
>>   anymore.
>>
> 
>>o simplifies the bash 'regexp' to snip away the '.c' and print the rest
>>
> 
> Hmm... is it faster than original?

I would say so, "b=${a%.*}" is always faster and legible than
                 "l=$((${#a}-2)); b=${a:0:$l}"
in the way it is used in your script.

Maybe not easily measurable but it seems obvious to me and is easier to 
read and overall time reported less time used for the whole script to 
run. ;)

And the second tiny cleanup regarding regexp was to use "${a:2}" instead 
of "${a:2:9999}". It should be an improvement too, if I remember the 
bash source correctly. But this is senseless nitpicking. The real speed 
improvement you get by avoiding the "LIST=`find -name '*.c' | xargs`".

>>I'm propably going to rewrite the python script in bash too, since I
>>don't run python on my distro (and I do not intend to use 2.5.x anytime
>>soon).
>>
> 
> Care to show the result to me?

Well, if there is a real interest from other parties, I will definitely 
spend some time to do it. OTOH, bash's regexp handling isn't as strong 
as python's AFAICS so it might be a pain in the ass to do it but this is 
getting off-topic.

Best regards,
Roberto Nibali, ratz

Re: Improved ksymoops output

[Russell King]

On Wed, Feb 13, 2002 at 10:05:55AM -0200, Denis Vlasenko wrote:
> Ksymoops with file names and optionally regexp matched email addrs
> ==================================================================
> Warning (compare_maps): ksyms_base symbol ... not found in System.map.  Ignoring ksyms_base entry
> ...<<tons of similar warnings>>...

Eww.  You get these warnings because ksymoops is no longer able to match
up System.map with the kernel ksyms (since you effectively changed the
name of every symbol in System.map).

> Call Trace: [<c0130e00>] [<c01459cf>] [<c0113ee7>] [<c0113e38>] [<c021049f>]
>    [<c0145d05>] [<c0146002>] [<c010644e>] [<c011b432>] [<c011b7e3>] [<c01071ff>]
> Warning (Oops_read): Code line not seen, dumping what data is available
> Trace; c0130e00 <__get_free_pages(mm/page_alloc.c)+10/1c>
> Trace; c01459cf <__pollwait(fs/select.c:viro@math.psu.edu,tester3@host.org)+33/90>

I don't call this format "better" nor "improved".

It might be better to have something like this following at the end:

File; __get_free_pages: mm/page_alloc.c
File; __pollwait: fs/select.c
File; do_select: fs/select.c
File; process_timeout: kernel/sched.c
File; restore_sigcontext: arch/i386/kernel/signal.c
File; sock_poll: net/socket.c
File; sys_gettimeofday: kernel/time.c
File; sys_select: fs/select.c
File; sys_setitimer: kernel/itimer.c

Maintainer; fs/select.c <viro@math.psu.edu> <tester3@host.org>

Yes, this would involve modifications to ksymoops.  Note how we grouped
the email addresses together, and also how we sorted the symbol to file
list.

This way you don't have to go around cutting random bits of text out of the
middle of lines, and the lines don't wrap column at 80; in other words, it
is more readable.

You also remove some duplication of information, which is always a bonus
IMHO.

-- 
Russell King (rmk@arm.linux.org.uk)                The developer of ARM Linux
             http://www.arm.linux.org.uk/personal/aboutme.html

Re: Improved ksymoops output

[Denis Vlasenko]

On 13 February 2002 08:15, Russell King wrote:
> > Trace; c0130e00 <__get_free_pages(mm/page_alloc.c)+10/1c>
> > Trace; c01459cf <__pollwait(fs/select.c:viro@math.psu.edu,tester3@host.org)+33/90>
>
> I don't call this format "better" nor "improved".
>
> It might be better to have something like this following at the end:
>
> File; __get_free_pages: mm/page_alloc.c
> File; __pollwait: fs/select.c
> File; do_select: fs/select.c
> File; process_timeout: kernel/sched.c
> File; restore_sigcontext: arch/i386/kernel/signal.c
> File; sock_poll: net/socket.c
> File; sys_gettimeofday: kernel/time.c
> File; sys_select: fs/select.c
> File; sys_setitimer: kernel/itimer.c
>
> Maintainer; fs/select.c <viro@math.psu.edu> <tester3@host.org>

After some thought I prefer file names on the "Trace;" lines.
"Maintainer;" is fine.

I have better script which does exactly this.
It does not use modified System.map.
It requires func2file.map and email2pattern.map.
Works as a filter for ksymoops. Sample output:

# ksymoops | add_file_email
Call Trace: [<c0130e00>] [<c01459cf>] [<c0113ee7>] [<c0113e38>] [<c021049f>]
   [<c0145d05>] [<c0146002>] [<c010644e>] [<c011b432>] [<c011b7e3>] [<c01071ff>]
Warning (Oops_read): Code line not seen, dumping what data is available

Trace; c0130e00 <__get_free_pages+10/1c>        mm/page_alloc.c
Trace; c01459cf <__pollwait+33/90>      fs/select.c
Trace; c0113ee7 <schedule_timeout+4f/98>        kernel/sched.c
Trace; c0113e38 <process_timeout+0/60>  kernel/sched.c
Trace; c021049f <sock_poll+1f/24>       net/socket.c
Trace; c0145d05 <do_select+209/214>     fs/select.c
Trace; c0146002 <sys_select+2d2/620>    fs/select.c
Trace; c010644e <restore_sigcontext+126/138>    arch/i386/kernel/signal.c
Trace; c011b432 <sys_setitimer+76/150>  kernel/itimer.c
Trace; c011b7e3 <sys_gettimeofday+1b/17c>       kernel/time.c
Trace; c01071ff <system_call+33/38>


1 warning issued.  Results may not be reliable.

Maintainer; fs/select.c:tester3@host.org,viro@math.psu.edu

Script is below
--
vda

add_file_email
==============
#!/usr/bin/python

import sys
import string
import re

#
# Build func->file dictionary
#
f=open('func2file.map', 'r')
func2file={}
l=f.readline()
while l <> '':
    l=l[:len(l)-1]
    t=string.split(l)
    func2file[t[0]]=t[1]
    l=f.readline()

#
# Read email:pattern list
#
f=open('email2pattern.map', 'r')
people=[]
l=f.readline()
while l <> '':
    l=l[:len(l)-1]
    people.append(l)
    l=f.readline()

#
# Read stdin, add file names and email addresses to Trace; lines
#
f=sys.stdin
l=f.readline()
maint={}
while l <> '':
    l=l[:len(l)-1]
    if l[:6]=='Trace;':
	#print '>'+l[:6]+'<',l[:6]=='Trace;'
	func=string.split(string.split(l,'<')[1],'+')[0]
	#print func
	if func2file.has_key(func):
	    file=func2file[func]
	    l=l+'\t'+file
	    for p in people:
		t=string.split(p,':')
		email=t[0]
		pattern=t[1]
		expr=re.compile(pattern)
		if expr.match(file):
		    if maint.has_key(file):
			maint[file][email]=''
		    else:
			maint[file]={email:''}
    print l
    l=f.readline()

#
# Print "Maintainer; file:email,email" lines
#
print
for m in maint.keys():
    print 'Maintainer;',
    l=m+':'
    for e in maint[m].keys():
	l=l+e+','
print l[:len(l)-1]