Enhanced KTR logging (was RE: Quality of FreeBSD)

From: Matthew Dillon (dillon_at_apollo.backplane.com)
Date: 07/22/05

  • Next message: Edwin: "Re: help w/panic under heavy load - 5.4" 
    Date: Fri, 22 Jul 2005 09:54:46 -0700 (PDT)
To: Robert Watson <rwatson@freebsd.org>

    :...
    :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>
    _______________________________________________
    freebsd-hackers@freebsd.org mailing list
    http://lists.freebsd.org/mailman/listinfo/freebsd-hackers
    To unsubscribe, send any mail to "freebsd-hackers-unsubscribe@freebsd.org"

  • Next message: Edwin: "Re: help w/panic under heavy load - 5.4"