Date: Fri, 22 Jul 2005 09:54:46 -0700 (PDT) From: Matthew Dillon <dillon@apollo.backplane.com> To: Robert Watson <rwatson@freebsd.org> Cc: freebsd-hackers@freebsd.org Subject: Enhanced KTR logging (was RE: Quality of FreeBSD) Message-ID: <200507221654.j6MGskBD076199@apollo.backplane.com> References: <200507212344.j6LNi9HU000683@ferens.net> <20050722004940.P16902@fledge.watson.org>
next in thread | previous in thread | raw e-mail | index | archive | help
:... :have an extensive instrumentation system named KTR(9). If you're :interested in giving it a try, you can find out more here: : : http://www.watson.org/~robert/freebsd/netperf/ktr/ : :This page is primarily targetted at tracing locks, memory allocation, and :context switching, but you can also trace I/O, bus operations, VFS :operations, and a range of other things. While my web page doesn't talk :about it, as it's generally focused on micro-tracing of kernel events, you :can also queue the event stream to disk using alq(9). The man pages have :more information. There are some neat tools, such as Jeff Roberson's :schedgraph, for managing and rendering trace results. :... :Robert N M Watson Speaking of KTR, I would recommend that you look at our implementation of it (modeled after the one in FreeBSD but somewhat more generic at the cost of being slightly more expensive). In particular, I added some trivial code which traces back two stack frames and provides the instruction pointer of the caller of the procedure that did the KTR log, and the caller of the caller of the procedure that did the KTR log. I then rewrote the ktrdump program to extract the kernel's namelist and provide actual symbolic names. The result was a *HUGE* improvement in the usefullness of KTR. Like night and day, in fact. The heart of the two-caller-traceback is the cpu_ktr_caller() function in /usr/src/sys/i386/i386/ktr.c. I recommend that you add the traceback facility to your own KTR implementation. http://www.dragonflybsd.org/cgi-bin/cvsweb.cgi/src/sys/i386/i386/ktr.c?rev=1.1&content-type=text/x-cvsweb-markup&only_with_tag=HEAD Here is an example of ktrdump -a output: index cpu timestamp caller2 caller1 ID file and line trace 0 0 78286413138797 pmap_remove_pages+455 zfree+33 tokens_get /usr/src/sys/kern/lwkt_token.c:426 REF=0xd71f2a54 TOK=0xc043e500 TD=0xcc2b7200 1 0 78286413139038 pmap_remove_pages+455 zfree+83 tokens_release /usr/src/sys/kern/lwkt_token.c:466 REF=0xd71f2a54 TOK=0xc043e500 TD=0xcc2b7200 2 0 78286413140030 pmap_remove_pages+455 zfree+33 tokens_get /usr/src/sys/kern/lwkt_token.c:426 REF=0xd71f2a54 TOK=0xc043e500 TD=0xcc2b7200 3 0 78286413140279 pmap_remove_pages+455 zfree+83 tokens_release /usr/src/sys/kern/lwkt_token.c:466 REF=0xd71f2a54 TOK=0xc043e500 TD=0xcc2b7200 -Matt Matthew Dillon <dillon@backplane.com>
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200507221654.j6MGskBD076199>