Backtraces

When the kernel panics, it prints a “backtrace”, that is, a summary of how your program got where it is, as a list of addresses inside the functions that were running at the time of the panic. You can also insert a call to debug_backtrace, prototyped in <debug.h>, to print a backtrace at any point in your code. debug_backtrace_all, also declared in <debug.h>, prints backtraces of all threads.

The addresses in a backtrace are listed as raw hexadecimal numbers, which are difficult to interpret. We provide a tool called backtrace to translate these into function names and source file line numbers. Give it the name of your kernel.o as the first argument and the hexadecimal numbers composing the backtrace (including the 0x prefixes) as the remaining arguments. It outputs the function name and source file line numbers that correspond to each address.

If the translated form of a backtrace is garbled, or doesn’t make sense (e.g. function A is listed above function B, but B doesn’t call A), then it’s a good sign that you’re corrupting a kernel thread’s stack, because the backtrace is extracted from the stack. Alternatively, it could be that the kernel.o you passed to backtrace is not the same kernel that produced the backtrace.

Sometimes backtraces can be confusing without any corruption. Compiler optimizations can cause surprising behavior. When a function has called another function as its final action (a tail call), the calling function may not appear in a backtrace at all. Similarly, when function A calls another function B that never returns, the compiler may optimize such that an unrelated function C appears in the backtrace instead of A. Function C is simply the function that happens to be in memory just after A.

Here’s an example. Suppose that Pintos printed out this following call stack:

Call stack: 0xc0106eff 0xc01102fb 0xc010dc22 0xc010cf67 0xc0102319
0xc010325a 0x804812c 0x8048a96 0x8048ac8.

You would then invoke the backtrace utility like shown below, cutting and pasting the backtrace information into the command line. This assumes that kernel.o is in the current directory. You would of course enter all of the following on a single shell command line, even though that would overflow our margins here:

backtrace kernel.o 0xc0106eff 0xc01102fb 0xc010dc22 0xc010cf67 0xc0102319 0xc010325a
0x804812c 0x8048a96 0x8048ac8

The backtrace output would then look something like this:

0xc0106eff: debug_panic (lib/debug.c:86)
0xc01102fb: file_seek (filesys/file.c:405)
0xc010dc22: seek (userprog/syscall.c:744)
0xc010cf67: syscall_handler (userprog/syscall.c:444)
0xc0102319: intr_handler (threads/interrupt.c:334)
0xc010325a: intr_entry (threads/intr-stubs.s:38)
0x0804812c: (unknown)
0x08048a96: (unknown)
0x08048ac8: (unknown)

The first line in the backtrace refers to debug_panic, the function that implements kernel panics. Because backtraces commonly result from kernel panics, debug_panic will often be the first function shown in a backtrace.

The second line shows file_seek as the function that panicked, in this case as the result of an assertion failure. In the source code tree used for this example, line 405 of filesys/file.c is the assertion

assert (file_ofs >= 0);

(This line was also cited in the assertion failure message.) Thus, file_seek panicked because it passed a negative file offset argument.

The third line indicates that seek called file_seek, presumably without validating the offset argument. In this submission, seek implements the seek system call.

The fourth line shows that syscall_handler, the system call handler, invoked seek.

The fifth and sixth lines are the interrupt handler entry path.

The remaining lines are for addresses below phys_base. This means that they refer to addresses in the user program, not in the kernel. If you know what user program was running when the kernel panicked, you can re-run backtrace on the user program, like so: (typing the command on a single line, of course):

backtrace tests/filesys/extended/grow-too-big 0xc0106eff 0xc01102fb 0xc010dc22
0xc010cf67 0xc0102319 0xc010325a 0x804812c 0x8048a96 0x8048ac8

The results look like this:

0xc0106eff: (unknown)
0xc01102fb: (unknown)
0xc010dc22: (unknown)
0xc010cf67: (unknown)
0xc0102319: (unknown)
0xc010325a: (unknown)
0x0804812c: test_main (...xtended/grow-too-big.c:20)
0x08048a96: main (tests/main.c:10)
0x08048ac8: _start (lib/user/entry.c:9)

You can even specify both the kernel and the user program names on the command line, like so:

backtrace kernel.o tests/filesys/extended/grow-too-big 0xc0106eff 0xc01102fb 0xc010dc22
0xc010cf67 0xc0102319 0xc010325a 0x804812c 0x8048a96 0x8048ac8

The result is a combined backtrace:

in kernel.o:

0xc0106eff: debug_panic (lib/debug.c:86)|
0xc01102fb: file_seek (filesys/file.c:405)|
0xc010dc22: seek (userprog/syscall.c:744)|
0xc010cf67: syscall_handler (userprog/syscall.c:444)|
0xc0102319: intr_handler (threads/interrupt.c:334)|
0xc010325a: intr_entry (threads/intr-stubs.s:38)|

in tests/filesys/extended/grow-too-big:

0x0804812c: test_main (...xtended/grow-too-big.c:20)|
0x08048a96: main (tests/main.c:10)|
0x08048ac8: _start (lib/user/entry.c:9)|

Here’s an extra tip: backtrace is smart enough to strip the Call stack: header and . trailer from the command line if you include them. This can save you a little bit of trouble in cutting and pasting. Thus, the following command prints the same output as the first one we used:

backtrace kernel.o Call stack: 0xc0106eff 0xc01102fb 0xc010dc22 0xc010cf67 0xc0102319
0xc010325a 0x804812c 0x8048a96 0x8048ac8.