7.2 Library tracing

On most UNIX machines there exists a tool for tracing the system calls executed by a program. If you haven't used one of these tools (e.g. ktrace) then now is a good time to learn. Being able to trace the User/Kernel interface is an excellent way to understand complex applications.

The ‘nana-libtrace’ facility generalises this idea to provide a GDB based function call tracer for all functions in which are defined in a particular library. For example the ‘make ex-libtrace’ command in the ‘gdb’ directory produces a trace of all calls to ‘libc’.

• ‘nana-libtrace a.out’ – reads a list of function names one per line from the standard input and writes the corresponding gdb(1) script to the standard output. Note that all functions specified in the input must exist in the executable for them to be passed through to the output. This may require compilation of your program with ‘-static’ linking.¹ For example:

            % gcc -g -static test.c -lm
            % ./nana-libtrace a.out >test.gdb
            printf
            write
            % cat test.gdb
            break printf
            command $bpnum
            silent
            where 1
            cont
            end
            break write
            command $bpnum
            silent
            where 1
            cont
            end
            % nana-run a.out -x test.gdb
            Breakpoint 1 at 0x1483: file /usr/.../libc/stdio/printf.c, line 65.
            Breakpoint 2 at 0x8c78
            #0  printf (fmt=0x1116 "** main()\n")
                at /usr/src/lib/libc/../libc/stdio/printf.c:65
            #0  0x8c78 in write ()
            ** main()
            #0  printf (fmt=0x1121 "** 1: %d\n")
                at /usr/src/lib/libc/../libc/stdio/printf.c:65
            #0  0x8c78 in write ()
            ** 1: 6
            #0  printf (fmt=0x112b "** 2: %d\n")
                at /usr/src/lib/libc/../libc/stdio/printf.c:65
            #0  0x8c78 in write ()
            ** 2: 7
            #0  printf (fmt=0x1135 "** 3: %d\n")
                at /usr/src/lib/libc/../libc/stdio/printf.c:65
            #0  0x8c78 in write ()
            ** 3: 8
            
            Program exited with code 010.
  

• ‘nana-libtrace a.out /usr/lib/libc.a’ – trace all calls to ‘libc’ from ‘a.out’. A subset of the output is given below:

            #0  printf (fmt=0x1135 "** 3: %d\n")
                at /usr/src/lib/libc/../libc/stdio/printf.c:65
            #0  vfprintf (fp=0xa1d4, fmt0=0x1135 "** 3: %d\n", ap=0xefbfd888 "\b")
                at /usr/src/lib/libc/../libc/stdio/vfprintf.c:428
            #0  vfprintf (fp=0xefbfd5b8, fmt0=0x1135 "** 3: %d\n", ap=0xefbfd888 "\b")
                at /usr/src/lib/libc/../libc/stdio/vfprintf.c:428
            #0  __sfvwrite (fp=0xefbfd5b8, uio=0xefbfd184)
                at /usr/src/lib/libc/../libc/stdio/fvwrite.c:68
            #0  0x8ff8 in memcpy ()
            #0  0x8ff8 in memcpy ()
            #0  __sfvwrite (fp=0xefbfd5b8, uio=0xefbfd184)
                at /usr/src/lib/libc/../libc/stdio/fvwrite.c:68
            #0  0x8ff8 in memcpy ()
            #0  fflush (fp=0xefbfd5b8) at /usr/src/lib/libc/../libc/stdio/fflush.c:60
            #0  __sflush (fp=0xefbfd5b8) at /usr/src/lib/libc/../libc/stdio/fflush.c:84
            #0  __swrite (cookie=0xa1d4, buf=0xefbfd1b8 "** 3: 8\nain()\n", n=8)
                at /usr/src/lib/libc/../libc/stdio/stdio.c:78
            #0  0x8c78 in write ()
            ** 3: 8
  

  Note that your library code must be compiled with ‘-g’ to put in the debugging information if you wish to have the arguments displayed symbolically. This is fairly easy on most systems, e.g on FreeBSD you edit the global compile options ‘/etc/make.conf’ and rebuild/install the entire system.

  Ideally we would also like to be able to trace only entry calls and not internal calls to libc. This can be done by inserting a counter which is incremented on call and decremented on return. We print the trace messages iff the counter is 1. This extension (perhaps to GNU libc) may be written if people are interested.