XSIM Trace output

XSIM trace output is produced by using xsim -t, xsim --trace or xsim --trace-to. The format provides an insight into the internal operations of the xcore which is not possible to see by using the hardware itself.

Here’s a random example of the output, taken from a two-tile processor:

tile[0]@0- -SI A-.----0004012c (write_switch_reg_send+  8) : out     res[r4(0x80020102)], r2(0x18) @3261
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3261
tile[0]@0- -SI A-.----0004012e (write_switch_reg_send+  a) : outct   res[r4(0x80020102)], 0x1 @3266
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3266
tile[0]@0- -SI A-.----00040130 (write_switch_reg_send+  c) : bf      r11(0x1), 0x9 @3271
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3271
tile[0]@0-P-SI A-.----00040132 (write_switch_reg_send+  e) : inct    r0(0x1), res[r4(0x80020102)] @3276
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3276
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3281
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3286
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3291
tile[0]@0- -SI A-.----00040132 (write_switch_reg_send+  e) : inct    r0(0x3), res[r4(0x80020102)] @3293
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3296
tile[0]@0- -SI A-.----00040134 (write_switch_reg_send+ 10) : eq      r0(0x1), r0(0x3), 0x3 @3298
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3301
tile[0]@0- -SI A-.----00040136 (write_switch_reg_send+ 12) : chkct   res[r4(0x80020102)], 0x1 @3303
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3306
tile[0]@0- -SI A-.----00040138 (write_switch_reg_send+ 14) : freer   res[r4(0x80020102)] @3308
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3311
tile[0]@0- -SI A-.----0004013a (write_switch_reg_send+ 16) : ldw     r4(0x0), sp[0x0] L[0x42000] @3313
tile[1]@0- -SI A-.----0004003a (_done               +  6) : bu      -0x1 @3316
tile[0]@0- -SI A-.----0004013c (write_switch_reg_send+ 18) : retsp   0x0 L[0x42000] @3318

Each row represents the execution of a single instruction. Here’s a quick overview of what it means. From left to right:

  • tile[0]: this is the tile executing the instruction

  • 0004012c: program counter address

  • (write_switch_reg_send+  8): the symbol and offset from it

  • out     res[r4(0x80020102)], r2(0x18): instruction

  • @3261: processor cycle (time, basically)

If you look closer, you can also see the contents of each register and, towards the bottom of the sample, memory access too (L[0x42000]).

Further detail is contained in the table below:

Trace output for XS1 processors

Tile

Core State

Address

Instruction

Mem

Cycle

Name from XN

I0

I1

I2

S0,S1(T0) .. S0,S1(Tn)

.

M

S

K

N

PC

(sym+offset):

name

operands

address

@val

- D

* P

- d

- a A i I p m s w

n status pairs

- m

- s

- k

- n

val rn(val) res[id]

L[adr] S[adr]
I0: - No debug interrupt
I0: D Instruction caused debug interrupt
I1: * Instruction excepted
I1: P Instruction paused
I2: - Not in debug mode
I2: d Tile in debug mode
S0: - Core not in use
S0: a Core active
S0: A Core active (the instruction being traced belongs to this core)
S0: i Core active with ININT bit set
S0: I Core active with ININT bit set (belongs to this core)
S0: p Core paused due to instruction fetch
S0: m Core paused with MSYNC bit set
S0: s Core paused withSSYNC bit set
S0: w Core paused with WAITING bit set
S1: - Interrupts and events disabled
S1: b Interrupts and events enabled
S1: i Interrupts enabled and events disabled
S1: e Interrupts disabled and events enabled
M: - MSYNC not set
M: m MSYNC set
S: - SSYNC not set
S: s SSYNC set
K: - INK not set
K: k INK set
N: - INENB not set
N: n INENB set
rn(val) Value of register n
res[id] Resource identifier
L/S[adr] Load from/Store to address