Enhanced KTR logging (was RE: Quality of FreeBSD)
dillon at apollo.backplane.com
Fri Jul 22 18:11:11 GMT 2005
:have an extensive instrumentation system named KTR(9). If you're
:interested in giving it a try, you can find out more here:
: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.
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
<dillon at backplane.com>
More information about the freebsd-hackers