<<<
:sectnums:
==== Execution Trace Buffer (TRACER)

[cols="<3,<3,<6"]
[grid="none"]
|=======================
| Hardware source files:  | neorv32_tracer.vhd    |
| Software driver files:  | neorv32_tracer.c      | link:https://stnolting.github.io/neorv32/sw/neorv32__tracer_8c.html[Online software reference (Doxygen)]
|                         | neorv32_tracer.h      | link:https://stnolting.github.io/neorv32/sw/neorv32__tracer_8h.html[Online software reference (Doxygen)]
| Top entity ports:       | none                  |
| Configuration generics: | `IO_TRACER_EN`        | implement TRACER module when `true`
|                         | `IO_TRACER_BUFFER`    | trace buffer depth, has to be zero or a power of two, min 1
|                         | `IO_TRACER_SIMLOG_EN` | write full trace log to file when `true` (simulation-only)
| CPU interrupts:         | fast IRQ channel 5    | tracing stop-address match interrupt (see <<_processor_interrupts>>)
|=======================

**Key Features**

* Delta-tracing of instruction execution
* Auto-stop tracing (and issue interrupt) when reaching a programmable instruction address
* Dump and inspect delta-trace directly from the firmware or via GDB


**Overview**

The NEORV32 tracer module allows to record program execution in order to find out how the CPU
arrived at a certain code point. It is fed by the CPU's <<_execution_trace_port>>.
In order to keep the data rate low, so-called _instruction delta tracing_ is used:

[quote, RISC-V Trace Specification, github.com/riscv-non-isa/riscv-trace-spec]
____
Instruction delta tracing, also known as branch tracing, works by tracking execution from a known
start address by sending information about the deltas taken by the program. Deltas are typically
introduced by jump, call, return and branch type instructions, although interrupts and exceptions are
also types of deltas. Instruction delta tracing provides an efficient encoding of an instruction sequence
by exploiting the deterministic way the processor behaves based on the program it is executing.
____

This means that only non-linear changes of the program counter are recorded. These _deltas_ are stored in a
a local memory (the trace buffer) and can be read by the debugger (e.g. GDB). The size of this trace buffer
is configurable via the `IO_TRACER_BUFFER` generic.

The program being executed can also read the trace buffer itself (stand-alone-mode, not debugger required).
In the dual-core configuration, for example, one CPU core can analyze the trace of the other CPU core.

.TRACER Demo Program
[TIP]
A demo program for the tracer can be found in `sw/example/demo_tracer`.


**Theory of Operation**

The tracer module provides four memory-mapped registers: the status and control register `CTRL`, a "stop-tracing"
address register `STOP_ADDR` and two read-only registers to read trace data (`DELTA_SRC` and `DELTA_DST`).

The trace module is enabled by setting the `TRACER_CTRL_EN` bit in the control register. If this bit is cleared,
the module i enabled and the internal trace buffer is cleared. Bit `TRACER_CTRL_HSEL` selects the hart / CPU core
that shall be traced. This bit is read-only zero for the single-core configuration.

Tracing is started by writing `1` to the `TRACER_CTRL_START` control register bit. Tracing can be stopped at any
time by manually writing `1` to the `TRACER_CTRL_START` control register bit. Software can check if tracing is
in progress by reading the `TRACER_CTRL_RUN`. Tracing is _automatically stopped_ when program execution reaches
the address in the `STOP_ADDR` register. Automatic trace stopping can be disabled by writing -1 to this register.

.Halt Tracing during Debug-Mode
[NOTE]
Whenever the CPU enters debug mode, either by a halt request from the debugger or by a (hard-coded) breakpoint or
watchpoint, tracing is paused until the CPU resumes normal operation.

During tracing, the module writes the instruction deltas to the internal buffer. The buffer is implemented as FIFO,
so that only the last _IO_TRACER_BUFFER_ instruction deltas are kept. At least one instruction delta is available
in the trace buffer when `TRACER_CTRL_AVAIL` is set. A single entry ("packet") of the trace buffer data can be read
via the two registers `DELTA_SRC` and `DELTA_DST`:

* `DELTA_SRC` provides the 31-bit instruction address of the branch source.
Bit 0 is set if this trace packet is the very first after trace start; it is cleared for all further packets.
* `DELTA_DST` provides the 31-bit instruction address of the branch destination.
Bit 0 is set if this branch was caused by a trap-entry; it is cleared if this branch was caused by a jump/call/branch instruction.

.Trace Buffer Read Access
[IMPORTANT]
The trace buffer's FIFO read-pointer automatically increments when reading `DELTA_DST`,
so make sure to read `DELTA_SRC` before `DELTA_DST`. The implementation as FIFO also
means that the **trace data can only be read once**.


**Tracer Interrupt**

The tracer module features a single interrupt that gets triggered when the traced program reached the address
stored in the module's `STOP_ADDR` register. The pending interrupt needs to be explicitly acknowledged/cleared
by writing `1` to the `TRACER_CTRL_IRQ_CLR` control register bit.


**Evaluating Trace Data from GDB**

Two simple functions for handling the tracer are implemented as GDB script. The script is located in the tracer
example program and can be imported into GDB using the `source` command:

.Importing the Tracer GDB Script
[source, gdb]
----
(gdb) source path/to/neorv32/sw/example/demo_tracer/neorv32_tracer.gdb
----

After sourcing, two additional commands are available that can be executed from the GDB command line:

* `tracer_get`: read-out the data from the trace buffer and print the execution history
* `tracer_start arg`: restart the tracer; the CPU ID has to be provided as argument (`arg`, 0 or 1)

Using the tracer from GDB is briefly illustrated in the following example:

.Using the Tracer from GDB (GDB started in `neorv32/sw/example/demo_tracer`)
[source, gdb]
----
(gdb) make clean elf <1>
...
(gdb) load <2>
...
(gdb) c <3>
...
(gdb) source neorv32_tracer.gdb <4>
(gdb) tracer_get <5>
[0] SRC: 0x3b0 -> DST: 0x2cc <TRACE_START>
Line 128 of "main.c" starts at address 0x3b0 <main+212> and ends at 0x3b4 <main+216>.
Line 68 of "main.c" starts at address 0x2cc <test_code> and ends at 0x2d0 <test_code+4>.
...
----
<1> Compile the demo program.
<2> Upload the compiled ELF.
<3> Start executing. The program will stop re-entering debug-mode when reaching main's `return` statement.
<4> Import the tracer helper functions script.
<5> Get trace log and print.


**Tracer Simulation Logging**

.Simulation-Only
[IMPORTANT]
This feature is available in simulation only.

The NEORV32 tracer module can also be used to generate a complete log of all executed instructions. Simulation
trace logging is enabled by the `IO_TRACER_SIMLOG_EN` top generic. This also requires the tracer is implemented
(`IO_TRACER_EN` = true). However, no specific configuration of the control register `CTRL` is required. During
simulation, all traced instructions are written to log files in the simulator's home folder:

* `neorv32.tracer0.log` for CPU 0
* `neorv32.tracer1.log` for CPU 1 (only if <<_dual_core_configuration>> is enabled)

The trace log is structured line by line where each line describes an executed instruction.
The start of an exemplary trace log might look like this:

.Exemplary cut-out from a simulation trace log (here: `neorv32.tracer1.log` showing boot of core 1)
[source, log]
----
52168 256630 0x000024f6 0xc00026f3 U csrrs       x13, cycle, x0
52169 256633 0x000024fa 0xc02025f3 U csrrs       x11, instret, x0
52170 256635 0x000024fe 0x0001     U c.addi      x0, x0, 0
52171 256647 0x00002500 0x0001     U c.addi      x0, x0, 0
52172 256650 0x00002502 0xc0002673 U csrrs       x12, cycle, x0
52173 256653 0x00002506 0xc0202573 U csrrs       x10, instret, x0
52174 256656 0x0000250a 0x00000073 U ecall
52175 256665 0x00003e94 0x34011073 M csrrw       x0, mscratch, x2 <TRAP_ENTRY> <1>
52176 256667 0x00003e98 0x7119     M c.addi16sp  x2, x2, -128
52177 256672 0x00003e9a 0xc206     M c.swsp      x1, 4(x2)
52178 256675 0x00003e9c 0x340110f3 M csrrw       x1, mscratch, x2
----
<1> This line is used for explanation (see below).

Column structure:

[start=1]
. `52175`: Instruction index ("order"); a linear increasing counter that starts at zero and increments with each executed instruction; printed as decimal integer.
. `256665`: Time stamp; a linear increasing counter that starts at zero and increments with each clock cycle; printed as decimal integer.
. `0x00003e94`: Instruction address (program counter); printed as hexadecimal 32-bit value (`0x` prefix).
. `0x34011073`: instruction word; printed as 32-bit or 16-bit (compressed isntructgion) hexadecimal value (`0x` prefix).
. `M`: Current operating mode / privilege level (`M` = machine-mode, `U` = user-mode, `D` = debug-mode); printed as single character.
. `csrrw`: The decoded instruction mnemonic. For unknown instructions `INVALID` is printed instead. Decompressed 16-bit instructions have a prefixed `c.` (e.g. `c.addi`).
. `x0, mscratch, x2`: Operands of the decoded instruction.
. If the CPU encounters a trap (synchronous exception or interrupt) `<TRAP_ENTRY>` is printed at the end of the line corresponding to the first instruction of the trap handler.

.Instruction Execution Time
[TIP]
The execution time of instruction _i_ (number of cycles required for retiring) can be calculated by
subtracting the current time stamp _i_ from the next time stamp _i+1_.

**Register Map**

.TRACER register map (`struct NEORV32_TRACER`)
[cols="<4,<2,<6,^2,<8"]
[options="header",grid="all"]
|=======================
| Address | Name [C] | Bit(s), Name [C] | R/W | Function
.9+<| `0xfff30000` .9+<| `CTRL` <| `0`    `TRACER_CTRL_EN`                            ^| r/w <| TRACER enable, reset module when 0
                                <| `1`    `TRACER_CTRL_HSEL`                          ^| r/w <| Hart select for tracing (`0` = CPU0, `1` = CPU1)
                                <| `2`    `TRACER_CTRL_START`                         ^| r/w <| Start tracing, flag always reads as zero
                                <| `3`    `TRACER_CTRL_STOP`                          ^| r/w <| Manually stop tracing, flag always reads as zero
                                <| `4`    `TRACER_CTRL_RUN`                           ^| r/- <| Tracing in progress when set
                                <| `5`    `TRACER_CTRL_AVAIL`                         ^| r/- <| Trace data available when set
                                <| `6`    `TRACER_CTRL_IRQ_CLR`                       ^| r/w <| Clear pending interrupt when writing `1`, flag always reads as zero
                                <| `10:7` `TRACER_CTRL_TBM_MSB : TRACER_CTRL_TBM_LSB` ^| r/- <| `log2(IO_TRACER_BUFFER)`: trace buffer depth
                                <| `31:11` _reserved_                                 ^| r/- <| _reserved_, hardwired to zero
| `0xfff30004` | `STOP_ADDR` | `31:0` | r/w | Stop-tracing-address register
.2+<| `0xfff30008` .2+<| `DELTA_SRC` <| `31:1` ^| r/- | Branch source address, set to `-1` to disable automatic stopping
                                     <| `0`    ^| r/- | `1` = very first instruction delta in current trace; `0` = any further instruction delta
.2+<| `0xfff3000c` .2+<| `DELTA_DST` <| `31:1` ^| r/- | Branch destination address
                                     <| `0`    ^| r/- | `1` = branch due trap entry (interrupt or synchronous exception); `0` = branch due to jump/call/branch instruction
|=======================
