CLI interface. Backend flushed warning. SDK 16.0

[Rasul Kishov]

Hi devs!

I just evaluating CLI library with nRF52 USB Dongle. Really easy to use and nice example code in SDK. 

While everything is working fine for me still I can't deal with issue getting "Backend flushed" warning.

I do have in main loop: 

 

    UNUSED_RETURN_VALUE(NRF_LOG_PROCESS());
    cli_process();

And I'm sure it's executing because I have LED manipulating non blocking code inside this loop also. 

This messages are printed in non periodic timer handler using NRF_LOG_INFO macro. 

If I trigger this timer using cli commands after few messeges I'm regulary getting the Backend flushed warning. 

But if I trigger this timer via another periodic timer automatically not only I don't see these warnings again after even 50 of them but cli commands is not causing this warnings also. 

If I'm trying to use few cli commands in between of two automatic periodic calls I can get this warning message again. 

This looks so wierd to me and I don't have any idea what is the reason of this behavior.  

It appears to me increasing CLI_EXAMPLE_LOG_QUEUE_SIZE doesn't change anything. The project is based on CLI example. 

I'm using 16.0 SDK and each timer handler execution after NRF_LOG_INFO macro starts ESB message transmission. 

[Rasul Kishov]

I found the solution. But I still don't understand what is going on. 

This code gives me warnings:

    NRF_LOG_RAW_INFO("Sending mes: '%c', MID 0x%X, NID 0x%X, UID 0x%X%X, ", 
            sendingMsg[0], 
            *(uint16_t *)(sendingMsg+1), 
            sendingMsg[3], 
            *(uint32_t *)(sendingMsg+4), 
            *(uint32_t *)(sendingMsg+8));
    if ('P' == sendingMsg[0] || 'C' == sendingMsg[0] || 'D' == sendingMsg[0] || 'N' == sendingMsg[0] || 'A' == sendingMsg[0]) {
        NRF_LOG_RAW_INFO("TTL %i, DATA 0x%X \r\n", 
            sendingMsg[12], 
            *(uint32_t *) (sendingMsg + 13));
    }
    if ('H' == sendingMsg[0]) NRF_LOG_RAW_INFO("TTL %i\r\n", sendingMsg[12]);

Rewriting this code by this way solved the problem:

    NRF_LOG_RAW_INFO("Sending mes: '%c', MID 0x%X, NID 0x%X, UID 0x%X%X, TTL %i, ", 
            sendingMsg[0], 
            *(uint16_t *)(sendingMsg+1), 
            sendingMsg[3], 
            *(uint32_t *)(sendingMsg+4), 
            *(uint32_t *)(sendingMsg+8), 
            sendingMsg[12]);
    NRF_LOG_RAW_INFO("DATA 0x%X\r\n", *(uint32_t *) (sendingMsg + 13));

[Rasul Kishov]

    NRF_LOG_RAW_INFO("Sending mes: '%c', MID 0x%X, NID 0x%X, UID 0x%X%X, TTL %i", 
            sendingMsg[0], 
            *(uint16_t *)(sendingMsg+1), 
            sendingMsg[3], 
            *(uint32_t *)(sendingMsg+4), 
            *(uint32_t *)(sendingMsg+8), 
            sendingMsg[12]);
    if ('H' == sendingMsg[0]) {
        NRF_LOG_RAW_INFO("\r\n");
    }
    else {
        NRF_LOG_RAW_INFO(", DATA 0x%X\r\n", *(uint32_t *) (sendingMsg + 13));
    }

This version is working fine too and btw doesn't compile without brackets, while it should. 

To me it looks like problem somehow related to NRF_LOG_RAW_INFO macro. 

[Einar Thorsrud]

Hi,

Regarding the original issue, "Backends flushed" is typically logged when the buffer is full due to not running cli_process() in time. For instance, if you call cli_process() in the main loop, but do a lot of logging before the main loop runs.

Regarding the other issue, NRF_LOG_RAW_INFO() should not cause problems without brackets. It will insert a few if's etc, but everything is on a single line (which is always the case with macros). I did a quick test on my end and was not able to reproduce an issue with it. Which toolchain and SDK version do you use? (That said, if statements without brackets are generally a bad idea, as it is easy to make the mistake of adding one line when debugging or similar, and forgetting that only the first will be conditional).

[Rasul Kishov]

Thank you very much for your answer. 

I'm using 16.0 SDK together with Segger Studio. 

I pretty sure and just tested it again. Code below gives compile error "'else' without previous if"

    if ('H' == sendingMsg[0]) NRF_LOG_RAW_INFO("\r\n");
    else NRF_LOG_RAW_INFO(", DATA 0x%X\r\n", *(uint32_t *) (sendingMsg + 13));
    

And this code compiles without errors: 

    if ('H' == sendingMsg[0]) {
        NRF_LOG_RAW_INFO("\r\n");
    }
    else NRF_LOG_RAW_INFO(", DATA 0x%X\r\n", *(uint32_t *) (sendingMsg + 13));
    

(Regarding if statements without brackets. It is actually in general a bad idea. But sometimes you really want to save some extra vertical space to get a better code reading experience, espessically for programs with complex logic and especcially at the early develepment stage).

Anyway I don't want to abuse engineer's time since original problem is resolved. Even though I still don't understand how those small changes can be related to warning I got. I'm pretty sure the cli_process() was processed fast enough.