One of the great strengths of strace as a debugging tool is that it shows you what a program is doing regardless of whether it was compiled with debug info or not. The downside of this is that you only see the program’s syscall. You can use this information to deduce what is happening in the program but you don’t see from where in the program those syscalls originate.

The good news is that if your program was compiled with debug info strace can actually show a stack trace for every syscall in your binary.

Example

To demonstrate this we just save the following program to hello.c:

#include <stdio.h>

void print_info()
{
    int num = 5;
    printf("== Info ==\n");
    printf("Hello World!\n");
    printf("Num: %d\n", num);
}

int main(int argc, char **argv)
{
    print_info();
    return 0;
}

This program uses the printf function to print three lines of output. This function is part of the C standard library. To actually output the text it has to call the operating system by using the syscall write. We will look for this later in the strace output.

To compile the program we enter the following command:

$ gcc -g -o hello hello.c

Now we can run it with strace using the --stack-trace option (alternatively you can use the equivalent short-form option-k):

$ strace --stack-trace ./hello

This will give us an output similar to this:

...
write(1, "Num: 5\n", 7Num: 5
)                 = 7
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__write+0x14) [0x11c574]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_file_write+0x35) [0x93965]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_do_write+0xb1) [0x92561]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_file_xsputn+0xcf) [0x93a9f]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(parse_printf_format+0xaf9) [0x60cb9]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_vfprintf+0x48e3) [0x6b733]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_printf+0xb3) [0x601a3]
 > /home/user/abstractexpr/strace-stacktrace/hello(print_info+0x4a) [0x11b3]
 > /home/user/abstractexpr/strace-stacktrace/hello(main+0x1d) [0x11d3]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_init_first+0x8a) [0x2a1ca]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x8b) [0x2a28b]
 > /home/user/abstractexpr/strace-stacktrace/hello(_start+0x25) [0x10a5]
exit_group(0)                           = ?
+++ exited with 0 +++
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_exit+0x1d) [0xee21d]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(erand48_r+0x196) [0x47a26]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(exit+0x1e) [0x47bae]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_init_first+0x91) [0x2a1d1]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x8b) [0x2a28b]
 > /home/user/abstractexpr/strace-stacktrace/hello(_start+0x25) [0x10a5]

What we see here is that after every syscall (in this example only write and exit_group are shown) strace prints a stack trace that led to the call of the syscall. The stack trace has to be read from the bottom to the top with the top line being the function that made the actual syscall.

Most of the lines in the stack trace are function calls in the dynamically linked standard library (libc.so.6). But if you look closely you will see two lines that refer to functions in our hello program:

...
 > /home/user/abstractexpr/strace-stacktrace/hello(print_info+0x4a) [0x11b3]
 > /home/user/abstractexpr/strace-stacktrace/hello(main+0x1d) [0x11d3]
...

We can see here that main has called print_info before the flow of control went to printf and from there deeper into the standard library.

At the end of each line, we see an address in square brackets. This is the address from where the function call occurred that ultimately led to the syscall. Unfortunately, strace doesn’t show us the source code file and the line number that this address relates to. But we can easily get this information with the addr2line tool:

$ addr2line -e hello 0x11b3
/home/user/abstractexpr/strace-stacktrace/hello.c:9

Prettifying the Stack Trace

Now that we know how to resolve a single address we could write a Python script to replace every single address in the output of strace with the output of addr2line.

I’ve already written such a script:

#!/usr/bin/env python3

import os
import sys

import subprocess

def usage():
    print("Usage: pretty_print_strace.py FILENAME")
    sys.exit(2)

if len(sys.argv) != 2:
    usage()

filename = sys.argv[1]

def handle_line(line):
    line = line.rstrip()
    if not line.startswith(" > ") or not line.endswith("]"):
        print(line)
        return
    enrich_line(line)

def enrich_line(line):
    line = line[3:]
    components = line.split(" ")
    binary_funcoffset = components[0]
    address = components[1]
    binary = binary_funcoffset.split("(")[0]
    address = address[1:]
    address = address[:-1]

    result = subprocess.run(["addr2line", "-e", binary, address], shell=False, capture_output=True, text=True)
    line_num_info = ""
    if result.returncode != 0:
        line_num_info = address
    else:
        line_num_info = result.stdout.rstrip()

    if line_num_info == "??:?":
        line_num_info = address

    print(f" > {binary_funcoffset} [{line_num_info}]")

with open(filename) as f:
    for line in f:
        handle_line(line)

Save it as pretty_print_strace.py and make it executable with:

$ chmod a+x pretty_print_strace.py

You can then execute strace again but use the -o option to tell it to write its output to a file:

$ strace -o strace.out –stack-trace ./hello

This output file can then be prettified with the following command:

$ ./pretty_print_strace.py strace.out > strace-pretty.out

The stack traces in the newly created file strace-pretty.out will then have a filename and a line number instead of an address for every stack trace entry where addr2line could resolve the address:

...
write(1, "Num: 5\n", 7)                 = 7
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__write+0x14) [./io/../sysdeps/unix/sysv/linux/write.c:26 (discriminator 1)]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_file_write+0x35) [./libio/./libio/fileops.c:1182]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_do_write+0xb1) [./libio/./libio/fileops.c:449 (discriminator 1)]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_file_xsputn+0xcf) [./libio/./libio/fileops.c:1244 (discriminator 2)]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(parse_printf_format+0xaf9) [./stdio-common/./stdio-common/printf_buffer_to_file.c:59 (discriminator 2)]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_vfprintf+0x48e3) [./stdio-common/./stdio-common/vfprintf-internal.c:1545]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_IO_printf+0xb3) [./stdio-common/./stdio-common/printf.c:37]
 > /home/user/abstractexpr/strace-stacktrace/hello(print_info+0x4a) [/home/user/abstractexpr/strace-stacktrace/hello.c:9]
 > /home/user/abstractexpr/strace-stacktrace/hello(main+0x1d) [/home/user/abstractexpr/strace-stacktrace/hello.c:14]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_init_first+0x8a) [./csu/../sysdeps/x86/libc-start.c:74]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x8b) [./csu/../csu/libc-start.c:128]
 > /home/user/abstractexpr/strace-stacktrace/hello(_start+0x25) [0x10a5]
exit_group(0)                           = ?
+++ exited with 0 +++
 > /usr/lib/x86_64-linux-gnu/libc.so.6(_exit+0x1d) [./posix/../sysdeps/unix/sysv/linux/_exit.c:30 (discriminator 1)]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(erand48_r+0x196) [./stdlib/./stdlib/exit.c:131]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(exit+0x1e) [:?]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_init_first+0x91) [./csu/../sysdeps/x86/libc-start.c:63]
 > /usr/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x8b) [./csu/../csu/libc-start.c:128]
 > /home/user/abstractexpr/strace-stacktrace/hello(_start+0x25) [0x10a5]

Interestingly, many locations in the standard library could be resolved here as well.

The two lines from our program look like this now:

...
 > /home/user/abstractexpr/strace-stacktrace/hello(print_info+0x4a) [/home/user/abstractexpr/strace-stacktrace/hello.c:9]
 > /home/user/abstractexpr/strace-stacktrace/hello(main+0x1d) [/home/user/abstractexpr/strace-stacktrace/hello.c:14]
...

So here we have it! A stack trace for every syscall recorded by strace and the name of the C file and the line number are present in every entry of the stack trace.