SEGGER RTT Viewer is not working for the nRF9160 on my nRF9160DK board

[Burt]

Hi, I am pretty certain I have used RTTViewer before on the nRF9160, albeit not frequently. I cannot remember if I only used it on custom nRF9160 boards or if I used it on the nRF9160DK. The problem now is that it gives me 3 choices for Target Device: NRF52, CORTEX-M33, and CORTEX-M4. Past experience tells me that CORTEX-M33 is not what I am looking for. What I need is NRF9160, and it is not in the list. Okay, I understand now that I have to enter the nRF9160_xxAA manually. Why does it know about the NRF52 automatically but not the 9160? I think it would automatically show me the 9160 on my custom boards that do not have an NRF52. This is certainly confusing but is this normal? But I have a more pressing concern...

I am using both UART backend and RTT backend for logging. RTT is useless--at least as it is configured here. I did a build with the UART backend disabled, but that did not help things. It made them worse, as a timeout ASSERT related to BLE HCI occurred and I was dead in the water. I had to reconnect--even though there were no indications that a disconnect had occurred.

With both backends enabled, here is what I am seeing from RTT

*** Booting nRF Connect SDK v3.1.1-e2a97fe2578a ***
*** Using Zephyr OS v4.1.99-ff8f0c579eeb ***
[00:00:00.359,283] <inf> central_uart: ble_init() entered... Initializing Bluetooth..
[00:00:00.365,234] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.365,264] <inf> fs_nvs: alloc wra: 0, fd0
[00:00:00.365,264] <inf> fs_nvs: data wra: 0, 1c
bt_init() entered...
[00:00:00.375,854] <inf> central_uart: ble_init() exited
[00:00:00.375,885] <inf> central_uart: Bluetooth initialized
[00:00:01.093,688] <wrn> bt_id: Read Static Addresses command not available
[00:00:01.094,024] <inf> bt_hci_core: HCI transport: H:4
[00:00:01.094,207] <inf> bt_hci_core: Identity: C6:BD:27:D3:7F:87 (random)
[00:00:01.094,238] <inf> bt_hci_core: HCI: version 1.0b (0x00) revision 0x0000, manufacturer 0x0000
[00:00:01.094,268] <inf> bt_hci_core: LMP: version 1.0b (0x00) subver 0x0000
[00:00:01.095,336] <dbg> central_uart: uart_
249

and here is what I am seeing from the UART

*** Booting nRF Connect SDK v3.1.1-e2a97fe2578a ***
*** Using Zephyr OS v4.1.99-ff8f0c579eeb ***
[00:00:00.359,283] <inf> central_uart: ble_init() entered... Initializing Bluetooth..
[00:00:00.365,234] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.365,264] <inf> fs_nvs: alloc wra: 0, fd0
[00:00:00.365,264] <inf> fs_nvs: data wra: 0, 1c
bt_init() entered...
[00:00:00.375,854] <inf> central_uart: ble_init() exited
[00:00:00.375,885] <inf> central_uart: Bluetooth initialized
[00:00:01.093,688] <wrn> bt_id: Read Static Addresses command not available
[00:00:01.094,024] <inf> bt_hci_core: HCI transport: H:4
[00:00:01.094,207] <inf> bt_hci_core: Identity: C6:BD:27:D3:7F:87 (random)
[00:00:01.094,238] <inf> bt_hci_core: HCI: version 1.0b (0x00) revision 0x0000, manufacturer 0x0000
[00:00:01.094,268] <inf> bt_hci_core: LMP: version 1.0b (0x00) subver 0x0000
[00:00:01.095,336] <dbg> central_uart: uart_cb: UART_RX_BUF_REQUEST
[00:00:01.095,367] <inf> central_uart: UART initialized successfully
[00:00:01.095,367] <inf> central_uart: NUS Client module initialized
Starting Bluetooth Central UART example
[00:00:01.162,506] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:01.162,719] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:01.162,750] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 252.16862 Build 1121034987
bt_init() line:4249
bt_init() line:4257
bt_init() line:4265
bt_init() line:4276
[00:00:01.169,128] <inf> bt_hci_core: HCI transport: H:4
[00:00:01.169,525] <inf> bt_hci_core: Identity: C6:BD:27:D3:7F:87 (random)
[00:00:01.169,555] <inf> bt_hci_core: HCI: version 6.1 (0x0f) revision 0x1069, manufacturer 0x0059
[00:00:01.169,799] <inf> bt_hci_core: LMP: version 6.1 (0x0f) subver 0x1069
[00:00:01.169,830] <inf> central_uart: Bluetooth ready
ble_ready() finished bt_conn_cb_register()
scan_start() finished bt_scan_init()
scan_start() finished bt_scan_cb_register()
scan_start() finished bt_scan_filter_add()
scan_start() finished bt_scan_filter_enable()
[00:00:01.185,974] <inf> central_uart: Scanning...
[00:00:01.231,689] <inf> central_uart: Filters matched. Address: E8:37:D4:53:1F:AC (random) connectable: 0
scan_connecting() entered...
connected() entered... conn_err=0
[00:00:01.332,885] <inf> central_uart: Connected: E8:37:D4:53:1F:AC (random)
gatt_req_send() encode() returns err=0
[00:00:01.433,837] <inf> central_uart: MTU exchange done
[00:00:01.633,941] <err> bt_smp: pairing failed (peer reason 0x8)
smp_pairing_complete() security_err=9 9==BT_SECURITY_ERR_UNSPECIFIED
bt_conn_security_changed() entered hci_err=31(31==BT_HCI_ERR_UNSPECIFIED) err=9
[00:00:01.634,857] <wrn> central_uart: Security failed: E8:37:D4:53:1F:AC (random) level 1 err 9
gatt_discover() entered...
gatt_req_send() encode() returns err=0
gatt_req_send() encode() returns err=0
gatt_req_send() encode() returns err=0
gatt_req_send() encode() returns err=0
gatt_req_send() encode() returns err=0
gatt_req_send() encode() returns err=0
gatt_req_send() encode() returns err=0
[00:00:02.333,862] <inf> central_uart: Service discovery completed
bt_nus_handles_assign() entered...
gatt_req_send() encode() returns err=0

Please help me learn how to make the RTT backend something other than a joke. Thank you.

Burt S.

[Burt]

Here is a slightly revised of my simple program that can be very useful to a Nordic Semi engineer responsible for testing RTT logging. It has a few lines that should be adjusted in various ways as suggested by the comments:

#include <zephyr/kernel.h>
#include <zephyr/logging/log.h>

#define LOG_MODULE_NAME simple
LOG_MODULE_REGISTER(LOG_MODULE_NAME);

int main(void)
{
        k_sleep(K_SECONDS(5));
        int count = 0;
        while(1){
                //uncomment the if statement to see how totally ridiculous the RTT logging is: if (count>100) continue;
                LOG_INF("The simplified AT host sample started");
                LOG_INF("Ready, count=%d", ++count);
                //uncomment optionally: ksleep(K_USEC(<your choice>);
        }
        return 0;
}

At high speeds (like with the commented lines commented) one must use CONFIG_LOG_MODE_IMMEDIATE, and this directly contradicts the default log mode (LOG_MODE_DEFERRED). Of course, with constant printing and no delay many lines will get lost, but given a tiny delay, slightly larger than 0, you will get fairly nice results. However, that is only for the case where the printing goes on ad infinitum. If you uncomment the if statement in the program, once again you find out who miserably useless the RTT logging is. This needs to be fixed.

Burt

[dejans]

Hi Burt, 

Is it that you get expected RTT log output if you do not use 'if' statement but you get only few lines in RTT output when using 'if' statement?

Best regards,
Dejan

[Burt]

Hi Dejan,

Yes, however I discovered a trick. Maybe the trick. But first, I apologize for misspelling k_sleep as ksleep. Second preliminary, there is also the question why nothing works with LOG_MODE_DEFERRED. Even "the trick" doesn't work with LOG_MODE_DEFERRED.

The trick sequence is:

1. bring up the RTTViewer Connect menu but don't click OK yet.

2. Push the reset button on the nRF9160DK and hold the processor (I test with the nRF9160) in reset.

3. Click OK on the RTTViewer and possibly wait a fraction of a second for the display to settle.

4. Release the nRF9160DK push button reset.

I see now that the if statement in my program was problematic because I had no k_sleep in the loop. I should have written

if (count>100) {k_sleep(K_MSEC(1));continue;}

or something similar (for the LOG_MODE_DEFERRED case, in particular).

So, it is looking like provided that I use my 4 step procedure above, I will get pretty much the same results with either RTT or UART back-ends. That is pleasing. I like to work on the command line and leave VS Code for when I need to do serious new code development as opposed to serious debugging problems/unexpected results in existing programs. Do you know whether VS Code performs my 4 step procedure automatically under the covers?

I only got into this crazy situation because we decided to use peripheral and central UART samples, and the lpuart developer made a change to lpuart prior to SDK v3.1.0 that is incompatible with central_uart, and I went down paths trying to figure out a workaround. I was so in buried in the details that I didn't realize that peripheral and central UART are not really what we need! So hopefully in the long run I will be able to get back to UART back end logging and not have any reason to use RTT back end. Even if it is just a matter of knowing when to push what buttons.

Burt

[dejans]

Hi Burt,

Burt said:

Do you know whether VS Code performs my 4 step procedure automatically under the covers?

In VS Code extension, JLinkExe is used for opening RTT communication and there is no reset.

Best regards,
Dejan

[Burt]

Thanks, Dejan. I was reading the SEGGER Forum, and there are 300 issues raised with RTT Viewer issues; many of which are the problem that only my four-step process solves. And yet, nowhere does SEGGER clearly explain what needs to be done. One user wrote a compelling statement, saying that a beginner will NEVER get RTT Viewer to work properly, and an experienced person MIGHT have luck after a great deal of effort. One limitation that I have not verified but would follow the pattern: unlike UART, you cannot take a soft reset and continue to log following the reset. I still find it bizarre that given three levels of documentation: SEGGER at bottom of the stack, followed by Zephyr OS, followed by NS documentation including a tutorial video, no decent user directions are provided. It's a strange beast.

I will close the ticket. Thank you for hearing my soapbox!