Micro Trace Buffer

Backtraces are a great tool for understanding where you are stopped in the program and the current state. But, what happens when our backtrace looks like this?

(gdb) backtrace
#0  HardFault_Handler () at asf/sam0/utils/cmsis/samd21/source/gcc/startup_samd21.c:284
#2  0x00000000 in exception_table ()

We obviously got where we are somehow but its not clear from the backtrace. Well, the Micro Trace Buffer is a way to sort out the history of the program rather than just the current state.

Unlike a backtrace, which shows the active function and its parents, the Micro Trace Buffer (MTB) records a history of what code was executed. The log it keeps is a circular buffer which always keeps a fixed amount of history. Once it is full, the oldest entry is overwritten with the newest entry and so on.

The MTB keeps the program counter history. The program counter keeps track of which assembly instruction is currently being executed. In basic procedural code flow such as the assembly for x = 0 code flows sequentially and the program counter is simply incremented. However, the program counter may change non-sequentially when a jump is made because of control flow statements such as if statements and loops. The MTB on the Cortex M0+ only records a packet when a jump is made because between jumps the code is sequential. When a jump is made it records both the program counter of where it is and the program counter of where its jumping to.

This raw program counter history is difficult to understand as a flat array so I've created a GDB plugin to reinterpret the program counter into the line of code that was run instead. This isn't a perfect approach though because a line of code may generate more than one assembly instruction and the compiler may also reorganize lines during optimization. But, its still better than assembly.

Code changes

Before we talk about the GDB side we need to initialize the MTB in our code itself. (I've already added it to CircuitPython for debug builds.)

First, create a global variable to hold the trace buffer in RAM. It must be called mtb to work with the GDB command. Notice it must also be aligned to the size of the MTB because the buffer wraps based on the lower bits of the address.

__attribute__((__aligned__(TRACE_BUFFER_SIZE * sizeof(uint32_t)))) uint32_t mtb[TRACE_BUFFER_SIZE];

Next, to turn on the MTB we must configure the starting position and flow policy to act as a circular buffer over mtb. The last configuration step configures the size of the buffer in bytes and enables the tracing. I recommend placing this code at the start of your main method so that you can read the MTB at any point after that.

REG_MTB_POSITION = ((uint32_t) (mtb - REG_MTB_BASE)) & 0xFFFFFFF8;
REG_MTB_FLOW = ((uint32_t) mtb + TRACE_BUFFER_SIZE * sizeof(uint32_t)) & 0xFFFFFFF8;
REG_MTB_MASTER = 0x80000000 + 6;

One thing to be aware of is that any loop will add many entries to the MTB. Empty infinite loops are even worse because they will fill up the entire buffer with nearly identical PCs! Infinite loops like this are popular in fault handlers when execution has effectively come to a hault. So, to preserve the MTB in fault handlers you should turn the tracing off before the empty infinite loop. Here is our basic HardFault_Handler:

void HardFault_Handler(void)
    // Turn off the micro trace buffer so we don't fill it up in the infinite
    // loop below.
    REG_MTB_MASTER = 0x00000000 + 6;
    while(true) {}

Installing GDB Helper

Now, once the trace is being written to RAM you can read it back with GDB. You can do this manually by printing the mtb variable but its more helpful to see the trace history by line of code.

First, download and source micro-trace-buffer.py into your gdb. Make sure you are using gdb with python enabled. In the arm toolchain use arm-none-eabi-gdb-py instead of arm-none-eabi-gdb.

(gdb) source micro-trace-buffer.py


Now, during a breakpoint you can run micro-trace-buffer or mtb for short to get the history from newest to oldest. (If it paginates you can type q then enter to quit early.) Here is an example:

(gdb) mtb
0x00018d94 asf/sam0/utils/cmsis/samd21/source/gcc/startup_samd21.c 282 1 times
0x00000001 no symtab symbol and line for , line 0
0x00000000 no symtab symbol and line for , line 0
0x00017ac4 asf/common/services/storage/ctrl_access/ctrl_access.c 447 1 times
0x00017aba asf/common/services/storage/ctrl_access/ctrl_access.c 437 1 times
0x00018574 asf/common/services/usb/class/msc/device/udi_msc.c 806 1 times
0x00018562 asf/common/services/usb/class/msc/device/udi_msc.c 794 1 times
0x00018394 asf/common/services/usb/class/msc/device/udi_msc.c 609 1 times
0x00018386 asf/common/services/usb/class/msc/device/udi_msc.c 594 2 times

The first number is the last pc to occur at that line in the log. The second part is the source file name. The third part is the source line number. The last part is the number of times the line occurs in the log. This is useful to condense tight loops.

Also, beware that this log only includes the pcs around jumps. If you see neighboring entries with the same file then the code between lines may have been run rather than jumped over.

So, going back to our example from the backtrace section, we can see that we jumped to a null function (pc 0x000000) from asf/common/services/storage/ctrl_access/ctrl_access.c 447. Bingo! Going there we can see a function call that must be null! Fix that and it works!

Wrap Up

GDB is a powerful tool for debugging SAMD21 boards. You can get really far with simple breakpoints, backtraces and the micro trace buffer. Good luck!

Last updated on 2017-08-11 at 03.38.33 PM Published on 2016-10-12 at 01.21.43 PM