<<<
: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]
----
51 929749 0x0000009c 0xfff44737 M lui           x14, 0xfff44000 <TRAP_ENTRY> <1>
52 929751 0x000000a0 0x00872103 M lw            x2, 2(x14)
53 929759 0x000000a4 0x00c72603 M c.lw          x12, 12(x14)
54 929767 0x000000a6 0xfff40737 M lui           x14, 0xfff40000
55 929770 0x000000aa 0x00072223 M sw            x14, 4(x0)
56 929778 0x000000ae 0x04a0006f M c.jal         x0, 74
57 929798 0x000000f8 0x80000197 M auipc         x3, 0x80000000
58 929800 0x000000fc 0x70818193 M addi          x3, x8, 1800
59 929824 0x00000100 0x0ff0000f M fence
60 929831 0x00000104 0x0000100f M fence.i
61 929853 0x00000108 0x30029073 M csrrw         x0, mstatus, x5
----
<1> This line is used for explanation (see below).

Column structure:

[start=1]
. `51`: Instruction index ("order"); a linear increasing counter that starts at zero and increments with each executed instruction; printed as decimal integer.
. `890622`: Time stamp; a linear increasing counter that starts at zero and increments with each clock cycle; printed as decimal integer.
. `0x000000c8`: Instruction address (program counter); printed as hexadecimal 32-bit value (`0x` prefix).
. `0xfff44737`: 32-bit instruction word; printed as hexadecimal 32-bit value (`0x` prefix); compressed 16-bit instructions are shown in their decompressed 32-bit format.
. `M`: Current operating mode / privilege level (`M` = machine-mode, `U` = user-mode, `D` = debug-mode); printed as single character
. `lui`: The decoded instruction mnemonic. For unknown instructions `INVALID` is printed instead. Decompressed 16-bit instructions have a prefixed `c.` (e.g. `c.lw`).
. `x14, 0xfff44000`: 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
|=======================
