Linux coresight arm64 : Incorrect data in cstrace.bin

Tue Jul 4 21:38:56 PDT 2023

Hi,

I am using linux 6.1 kernel coresight framework to capture ETM trace. 
Enabled coresight driver and added coresight component device node 
in DTS. With that, we could probe all coresight components. 

But when we do capture using sysfs and then read the trace.bin using 
ptm2human we see invalid trace data.  Trace content changes on each 
capture. Any pointers to help narrow down the issue? 

Tried: sysfs capture and perf (with OpenCSD enabled)

Development board: VCK190 :
 https://docs.xilinx.com/r/en-US/ug1366-vck190-eval-bd https://www.xilinx.com/support/documents/architecture-manuals/am011-versal-acap-trm.pdf

xilinx-vck190-20231:/home/petalinux# dmesg | grep -i amba
[    0.301054] Serial: AMBA PL011 UART driver
[    0.306226] amba f0c20000.funnel: Fixing up cyclic dependency with f0d70000.etm
[    0.313624] amba f0c20000.funnel: Fixing up cyclic dependency with f0d30000.etm
[    0.321110] amba f0c30000.etf: Fixing up cyclic dependency with f0c20000.funnel
[    1.470247] Serial: AMBA driver
xilinx-vck190-20231:/home/petalinux# dmesg | grep -i coresight
[    1.865006]  cs_system_cfg: CoreSight Configuration manager initialised
[    1.876858] coresight etm0: CPU0: etm v4.0 initialized
[    1.885666] coresight etm1: CPU1: etm v4.0 initialized
[    1.894435] coresight-cpu-debug f0d00000.debug1: Coresight debug-CPU0 initialized
[    1.902072] coresight-cpu-debug f0d40000.debug1: Coresight debug-CPU1 initialized

xilinx-vck190-20231:/home/petalinux# ls /sys/bus/coresight/devices/
etm0      etm1      funnel0   tmc_etf0

 cd /sys/bus/coresight/devices/ 
echo 1 > tmc_etf0/enable_sink 
echo 1 > etm0/enable_source 
echo 0 > etm0/enable_source 
echo 0 > tmc_etf0/enable_sink 
cd /root/ dd if=/dev/tmc_etf0 of=cstrace_28Jun.bin 

./ptm2human/ptm2human -e -i cstrace.bin -d 

Reading cstrace.bin etb_format.c:decode_etb_stream:136 - Found a NULL_TRACE_SOURCE ID in the ETB data packet etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 0 There is no valid data in the stream of ID 0 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 1 There is no valid data in the stream of ID 1 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 2 There is no valid data in the stream of ID 2 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 3 There is no valid data in the stream of ID 3 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 4 There is no valid data in the stream of ID 4 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 5 There is no valid data in the stream of ID 5 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 6 There is no valid data in the stream of ID 6 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 7 There is no valid data in the stream of ID 7 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 8 There is no valid data in the stream of ID 8 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 9 There is no valid data in the stream of ID 9 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 10 There is no valid data in the stream of ID 10 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 11 There is no valid data in the stream of ID 11 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 12 There is no valid data in the stream of ID 12 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 13 There is no valid data in the stream of ID 13 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 14 There is no valid data in the stream of ID 14 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 15 There is no valid data in the stream of ID 15 etb_format.c:decode_etb_stream:177 - There are 0 bytes in the stream 16 There is no valid data in the stream of ID 16 etb_format.c:decode_etb_stream:177 - There are 3742 bytes in the stream 17 Decode trace stream of ID 17 Syncing the trace stream... etmv4.c:etmv4_synchronization:1334 - MAX_SPEC_DEPTH = 0 etmv4.c:etmv4_synchronization:1335 - P0_KEY_MAX = 0 etmv4.c:etmv4_synchronization:1336 - COND_KEY_MAX_INCR = 0 etmv4.c:etmv4_synchronization:1337 - CONDTYPE = 0 etmv4.c:etmv4_synchronization:1338 - COMMOPT = 0 ERROR: First payload byte of async is not correct ERROR: Invalid async packet ERROR: Payload bytes of async are not correct ERROR: Invalid async packet ERROR: Payload bytes of async are not correct ERROR: Invalid async packet ERROR: Payload bytes of async are not correct

I also tried OpenCSD integration with PERF.

0x1e0 at perf.data [0x90]: event: 69    
.                                    
. ... raw event: size 144 bytes  
.  0000:  45 00 00 00 00 00 90 00 04 00 00 00 00 00 00 00  E...............
.  0010:  48 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  H...............
.  0020:  00 00 00 00 00 00 00 00 74 03 00 00 00 00 00 00  ........t.......
.  0030:  49 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00  I...............
.  0040:  01 00 00 00 00 00 00 00 74 03 00 00 00 00 00 00  ........t.......
.  0050:  4a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  J...............
.  0060:  00 00 00 00 00 00 00 00 74 03 00 00 00 00 00 00  ........t.......
.  0070:  4b 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00  K...............
.  0080:  01 00 00 00 00 00 00 00 74 03 00 00 00 00 00 00  ........t.......

0 0 0x1e0 [0x90]: PERF_RECORD_ID_INDEX nr: 4                               
 ... id: 72  idx: 0  cpu: 0  tid: 884                                      
 ... id: 73  idx: 1  cpu: 1  tid: 884                                      
 ... id: 74  idx: 0  cpu: 0  tid: 884                                      
 ... id: 75  idx: 1  cpu: 1  tid: 884                                      

0x270 at perf.data [0xc8]: event: 70           
.                                    
. ... raw event: size 200 bytes      
.  0000:  46 00 00 00 00 00 c8 00 03 00 00 00 00 00 00 00  F...............
.  0010:  01 00 00 00 00 00 00 00 02 00 00 00 08 00 00 00  ................
.  0020:  00 00 00 00 00 00 00 00 40 40 40 40 40 40 40 40  ........@@@@@@@@
.  0030:  00 00 00 00 00 00 00 00 07 00 00 00 00 00 00 00  ................
.  0040:  40 08 00 00 00 00 00 00 10 00 00 00 00 00 00 00  @...............
.  0050:  a1 0e 00 28 00 00 00 00 01 f4 00 41 00 00 00 00  ...(.......A....
.  0060:  88 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
.  0070:  cc 00 00 00 00 00 00 00 40 40 40 40 40 40 40 40  ........@@@@@@@@
.  0080:  01 00 00 00 00 00 00 00 07 00 00 00 00 00 00 00  ................
.  0090:  40 08 00 00 00 00 00 00 12 00 00 00 00 00 00 00  @...............
.  00a0:  a1 0e 00 28 00 00 00 00 01 f4 00 41 00 00 00 00  ...(.......A....
.  00b0:  88 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
.  00c0:  cc 00 00 00 00 00 00 00                          ........        

0 0 0x270 [0xc8]: PERF_RECORD_AUXTRACE_INFO type: 3                        
- log 58/58 100%

Thanks,
Radhey