trice l -p JLINK -args "..." cannot locate RTT control block, but provides string which does!

[jersuNF]

Describe the bug
Other SEGGER tools than JLinkRTTLogger assumes ASCII characters and use FF 00 to FF 0F as a terminal switch command and filter that out causing Trice data disturbances.

Using Trice to call the JLinkRTTLogger and using a temporary file for reading/writing fails in ... RTT Control Block not found. Cannot get data.
But the "-verbose" logs provides a string which I assume is the call to the JLinkRTTLogger, and that works stand-alone outside of Trice.

Attempting to use trice tool to invoke JLinkRTTLogger with associated output
<terminal_1>$: trice l -p JLINK -args "-device NRF52840_XXAA -if SWD -speed 4000 -RTTAddress 0x0000000020009390 -RTTChannel 0" -verbose
No logfile writing...
Read ID List file til.json with 20 items.
Read ID location information file li.json with 5 items.
port: JLINK arguments: -device NRF52840_XXAA -if SWD -speed 4000 -RTTAddress 0x0000000020009390 -RTTChannel 0
LINK executable JLinkRTTLogger and dynamic lib JLinkARM expected to be in path for usage.
Start a process: JLinkRTTLogger with needed lib JLinkARM and args:
0 -device
1 NRF52840_XXAA
2 -if
3 SWD
4 -speed
5 4000
6 -RTTAddress
7 0x0000000020009390
8 -RTTChannel
9 0
10 temp/trice-3732997421.bin
/usr/bin/JLinkRTTLogger -device NRF52840_XXAA -if SWD -speed 4000 -RTTAddress 0x0000000020009390 -RTTChannel 0 temp/trice-3732997421.bin
SEGGER J-Link RTT Logger
Compiled Nov 23 2022 16:12:13
(c) 2016-2017 SEGGER Microcontroller GmbH, www.segger.com
Solutions for real time microcontroller applications

Default logfile path: /home/jerry/.config/SEGGER

Connected to:
SEGGER J-Link ARM
S/N: 821011057

Searching for RTT Control Block...RTT Control Block not found. Cannot get data.

Shutting down... Done.trice is watching and reading from temp/trice-3732997421.bin
Encoding is TREX
exit status 255
^C#################################### interrupt ####################################
Closing link device.
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x5f1f86]

goroutine 18 [running]:
github.com/rokath/trice/internal/link.(*Device).Close(0xc0000e2480)
/home/jerry/Documents/Nofence/TRICE/trice/internal/link/link.go:133 +0x86
github.com/rokath/trice/internal/translator.handleSIGTERM({0x745340, 0xc0000128b8}, {0x7f4656a8e818, 0xc0000e2480})
/home/jerry/Documents/Nofence/TRICE/trice/internal/translator/translator.go:95 +0x1e5
created by github.com/rokath/trice/internal/translator.Translate
/home/jerry/Documents/Nofence/TRICE/trice/internal/translator/translator.go:77 +0xa45

Attempt to use the string provided by the trice tool to see if the JLinkRTTLogger is failing in itself, with the outputs
<terminal_1>$: /usr/bin/JLinkRTTLogger -device NRF52840_XXAA -if SWD -speed 4000 -RTTAddress 0x0000000020009390 -RTTChannel 0 temp/trice-2980179785.bin
SEGGER J-Link RTT Logger
Compiled Nov 23 2022 16:12:13
(c) 2016-2017 SEGGER Microcontroller GmbH, www.segger.com
Solutions for real time microcontroller applications

Default logfile path: /home/jerry/.config/SEGGER

Connected to:
SEGGER J-Link ARM
S/N: 821011057

Searching for RTT Control Block...OK.
3 up-channels found:
0: Terminal
1:
2:
Selected RTT Channel description:
Index: 0
Name: Terminal
Size: 15360 bytes.

Output file: temp/trice-2980179785.bin

Getting RTT data from target. Press any key to quit.

Transfer rate: 0 Bytes/s Data written: 34 Bytes
Transfer rate: 0 Bytes/s Data written: 34 Bytes
Shutting down... Done.

Versions of code and tools
commit 9977bb5 (HEAD -> master, origin/master, "renamed back accidently rename"

go version go1.20.2 linux/amd64

Ubuntu 20.04

Expected behavior
I expect the trice tool call to correctly find the RTT control block.

Screenshots

Additional context
The same thing happens when not using the -RTTAddress or using -RTTSearchRanges.

[rokath]

The trice tool does not search for any RTT ranges, it can use the JLinkRTTLogger only as black box.

Also I am not sure if the JLink tools CLI are case sensitive. In the manual they write -Device ... and not -device ....

The panic you got is interesting. I will check that later, but it is a different question.

I never tried like -RTTAddress 0x0000000020009390. How you figured out this specific address? I can imagine it is dependent on the current linker result and a matter of change. Does it make sense to do it this way?

I only used it like -RTTSearchRanges 0x20000000 0x1000 with values specific to the used MCU. If you specify the MCU with -Device ... you probably do not need to specify a -RTT... switch at all because the JLink tools know the MCU specific search ranges. These values probably make sense if you work with similar MCU types and you do not specify the MCU type.

Anyway it is strange that the JLinkRTTLogger with the identical command line could find the RTT Control Block in one case and in the other not. Is this reproducable with the identical binaries?

Maybe it has to do with access rights? Can you try it with root rights?

[jersuNF]

About case sensitivity the point is moot because the string which works looks the same as the one which fails. But I tried and it appears to be not-sensitive.

The address may be found as such: cat build/zephyr/zephyr.map | grep _SEGGER_RTT
It is the address of the .bss._SEGGER_RTT symbol in the map. This was only for debug purposes and sanity. The JLinkRTTLogger understands that aswell but Trice fails when using the same cmd-string.

I tried with ~/Downloads/trice-0.56.4 and also with trice built from repository on:
commit 9977bb5 (HEAD -> master, origin/master, origin/HEAD)

I'll investigate different versions of JLinkRTTLogger.

It still fails with sudo infront.

[rokath]

Just for information: RTT under Windows worked fine until a certain time. Than I had to change the default location for the temporary file from the appdata folder to the project folder.

I know for sure, that JLinkRTTLogger worked fine with Debian some time ago. I will tryout it again.

[rokath]

I could reproduce your issue with Debian and the JLink version 7.86f. Than I installed JLink version 6.92, what I recall, I was using some time. Does not work either.

Starting JLinkRTTLogger with an & at the end of the commandline did not work either. It seems to be connected somehow with background activity.

What worked: JLinkRTTLogger -Device ... ... ./temp/log.bin in one terminal and in a second terminal trice l -p FILE -args="./temp/log.bin.

Hope, that gets you started.

[rokath]

It should be possible let trice connect direct to the gdb server without using JLinkRTTLogger at all: https://github.com/openweave/openweave-nrf52840-lock-example/blob/master/start-jlink-gdb-server.sh. But I am not sure if the FF n problem exists then again. This could help too: https://mcuoneclipse.com/2015/03/25/command-line-programming-and-debugging-with-gdb/. Please check also https://wiki.segger.com/RTT#RTT_communication for additional hints.

[rokath]

Running this in Debian:

JLinkGDBServer \
-device STM32F030R8 \
-endian little \
-if SWD \
-speed 4000 \
-nolocalhostonly \
-noir \
-nohalt \
-notimeout \
-noreset \
-select USB \
-strict \
-RTTTelnetPort 4444 \

allows to get with trice l -p TCP4 -args localhost:4444 the logs. Omitting -RTTTelnetPort 4444 is possible. Then port 19021 is to use. I found no hint how to specify the RTTSearchRanges and other settings like channel selection. It works probably because the RTTSearchRanges are MCU specific.

With openOCD, RTT transfer is possible as well. I used openocd.cfg. Hopefully I can integrate both paths into trice tool soon to make is a bit more handy.

[jersuNF]

Thank you for the reply!
That's another interesting way to get the logs out, it works for me also using JLinkGDBServer.
But the errors are exactly the same as when using the JLinkExe(JLink commander) and localhost/TCP4, which is the filtering issue of SEGGER tools. I get this :(

Can the Trice tool be updated somehow to not send those sensitive frames? that would mean customized COBS or using another encoding? Best regards

[rokath]

Thanks for the info. I probably overlooked that or had simply "luck" yesterday night. I would not expect this issue with openOCD. Anyway, JLINK is an important technique. Of course it is possible to make an special COBS filtering out these sequences. I thought about this in the past. But this takes a lot of effort in the wrong direction. The JLinkGDBServer is for sure usable in a "normal" way, as it shows with JLinkRTTLogger. I think we should find out how. Maybe Wireshark can give the answer.

[rokath]

I checked again: The cycle error at the beginning is allowed, when you start fresh. Does it occur also inside of the data stream?

[rokath]

Look at this:

inconsistent TCOBSv1 buffer: [83 69 71 71 69 82 32 74 45 76 105 110 107 32 86 55 46 56 52 98 32 45 32 82 101 97 108 32 116 105 109 101 32 116 101 114 109 105 110 97 108 32 111 117 116 112 117 116 13 10 83 69 71 71 69 82 32 74 45 76 105 110 107 32 65 82 77 32 86 49 48 46 49 44 32 83 78 61 54 48 48 49 49 48 54 53 53 13 10 80 114 111 99 101 115 115 58 32 74 76 105 110 107 71 68 66 83 101 114 118 101 114 46 101 120 101 13 10 89 197 33 99 192 33 0]
Apr  4 16:44:02.175071  TCP4:             RFLInit.c   369              CYCLE: 193 not equal expected value 192 - adjusting. Now 1 CycleEvents
Apr  4 16:44:02.175577  TCP4:  Hello! 👋🙂

This is a plain text message generated by SEGGER (it ends with the 3rd 13 10 ) combined with the very first trice message. It is the same as you got. In my case are following 89 197 33 99 192 33 0:
2 bytes trice message ID, 4 bytes timestamp (the 99 encodes 3 zeroes), cycle counter 192, payload size 33 (an encoded 0) and the 0-delimiter. In your case the same, but without timestamp. The 192 is the initial value for the cycle counter. Because the trice tool tries to interpret all until the 0-delimiter as trice message it cannot read it and discards it. This could be done better. You can prove it by transmitting the very first trice message twice.
There is an 0xFF n issue (#402 (comment)) with JLinkGDBServer:
Code:

    trice8(  iD( 1562), "FF 00 FF 11 FF: %02x %02x %02x %02x   %02x %02x %02x %02x   %02x %02x %02x %02x\n", 0xFF, 0, 0xFF, 1, 0xFF, 2, 0xFF, 3, 0xFF, 4, 0xFF, 5 );
    trice16( iD( 2265), "FF 00 FF 11 FF: %04x %04x %04x %04x   %04x %04x %04x %04x   %04x %04x %04x %04x\n", 0xFF00, 0xFF01, 0xFF02, 0xFF03, 0xFF04, 0xFF05, 0xFF06, 0xFF07, 0xFF08, 0xFF09, 0xFF0A, 0xFF0B );
    trice32( iD( 7655), "FF 00 FF 11 FF: %08x %08x %08x %08x   %08x %08x %08x %08x\n", 0xFF00FF01, 0xFF02F03, 0xFF04FF05, 0xFF06FF07, 0xFF08FF09, 0xFF0AFF0B, 0xFF0CFF0D, 0xFF0EFF0F );

Ouput:

               main.c   115              FF 00 FF 11 FF: ff 00 ff 01   ff 02 ff 03   ff 04 ff 05
               main.c   116              FF 00 FF 11 FF: ff00 ff01 ff02 ff03   ff04 ff05 ff06 ff07   ff08 ff09 ff0a ff0b
               main.c   117              FF 00 FF 11 FF: ff00ff01 0ff02f03 ff04ff05 ff06ff07   ff08ff09 ff0aff0b ff0cff0d ff0eff0f

[rokath]

In master branch this is fixed now:

SEGGER J-Link V7.86e - Real time terminal output
J-Link STLink V21 compiled Aug 12 2019 10:29:20 V1.0, SN=775351129
Process: UV4.exe
Apr  5 10:13:50.496956  TCP4:                main.c    78              Trice check range is [20...400)
Apr  5 10:13:50.497953  TCP4:         triceConfig.h   177    0,000_077      NUCLEO-F030R8     TRICE_MODE 222     
Apr  5 10:13:50.497953  TCP4:         triceConfig.h   178                   ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~     
Apr  5 10:13:50.498950  TCP4:         triceConfig.h   179                    Trice 2x half buffer size:1024      
Apr  5 10:13:50.498950  TCP4:         triceConfig.h   182        0_087      ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~     
Apr  5 10:13:50.498950  TCP4:                main.c   115              FF 00 FF 11 FF: ff 00 ff 01   ff 02 ff 03   ff 04 ff 05
Apr  5 10:13:50.498950  TCP4:                main.c   116              FF 00 FF 11 FF: ff00 ff01 ff02 ff03   ff04 ff05 ff06 ff07   ff08 ff09 ff0a ff0b
Apr  5 10:13:50.499948  TCP4:                main.c   117              FF 00 FF 11 FF: ff00ff01 0ff02f03 ff04ff05 ff06ff07   ff08ff09 ff0aff0b ff0cff0d ff0eff0f
Apr  5 10:13:50.499948  TCP4:          triceCheck.c    72    0,000_102 A TRice message containing a newline
Apr  5 10:13:50.499948  TCP4:                                          before the line end