nRF52 RTT Log Not Showing All Messages

[Muhammet YILDIZ]

Hello,

I am using nRF52832, s132_nrf5.0.0_softdevice.

I am trying to build a ble gsm gateway.

I have 3 different peripheral devices. They have some services. 

On my gateway software, i am posting some debug message with nrf_log_info, nrf_log_warning, nrf_log_error and nrf_log_debug.

When i run my gateway, on RTT software i see string below. As i understand, somehow strings are not fully posted.

"<debug> ble_db_disc: Starting discovery of service with UUID 0x181A on connection handle 0x0.
<debug> ble_db_disc: Service UUID 0x181A not found.
<debug> ble_db_disc: Starting discovery of service with UUID 0x1 on connection handle 0x0.
<debug> ble_db_disc: Service UUID 0x1 not found.
<debug> ble_db_disc: Starting discovery of service with UUID 0x6 on connection handle 0x0.
<debug> ble_gatt: Peer on connection 0x0 requested a data length of 251 bytes.
<debug> ble_gatt: Updating data length to 27 bytes on connection 0x0.
<debug> ble_gatt: Data length updated to 27 on connection 0x0.
<debug> ble_gatt: max_rx_octets: 27
<debug> ble_gatt: max_tx_octets: 27
<debug> ble_gatt: max_rx_time: 328
<debug> ble_gatt: max_tx_time: 328
<debug> ble_db_disc: Found service UUID 0x6.
<debug> ble_db_disc: Discovery of service with UUID 0x6 completed with success on connection handle 0x0.
<debug> app: Call to ble_accs_on_db_disc_evt for instance 0 and link 0x0!
<debug> ble_accs_c: Accleration Service discovery failure at peer.
<debug> app: Call to ble_ess_on_db_disc_evt for instance 0 and link 0x0!
<debug> ble_ess_c: Environment Sensing Service discovery failure at peer.
<debug> app: Call to ble_dists_on_db_disc_evt for instance 0 and link 0x0!

link 0x0!
r.
<debug> app: Call to ble_ess_on_db_disc_evt for instance 0 and link 0x0!
<debug> ble_ess_c: Environment Sensing Service discovery failure at peer.
link 0x0!

link 0x0!
r.
ink 0x0!"

I need to see all the string. Otherwise i cant find the problem on the gateway. So i cant finish the software to make production.

I dont know how to add these texts as code or quote.

Here is my sdk_config.h file:

// <h> nRF_Log

//==========================================================
// <e> NRF_LOG_BACKEND_RTT_ENABLED - nrf_log_backend_rtt - Log RTT backend
//==========================================================
#ifndef NRF_LOG_BACKEND_RTT_ENABLED
#define NRF_LOG_BACKEND_RTT_ENABLED 1
#endif
// <o> NRF_LOG_BACKEND_RTT_TEMP_BUFFER_SIZE - Size of buffer for partially processed strings.
// <i> Size of the buffer is a trade-off between RAM usage and processing.
// <i> if buffer is smaller then strings will often be fragmented.
// <i> It is recommended to use size which will fit typical log and only the
// <i> longer one will be fragmented.

#ifndef NRF_LOG_BACKEND_RTT_TEMP_BUFFER_SIZE
#define NRF_LOG_BACKEND_RTT_TEMP_BUFFER_SIZE 64
#endif

// </e>

// <e> NRF_LOG_BACKEND_UART_ENABLED - nrf_log_backend_uart - Log UART backend
//==========================================================
#ifndef NRF_LOG_BACKEND_UART_ENABLED
#define NRF_LOG_BACKEND_UART_ENABLED 0
#endif
// <o> NRF_LOG_BACKEND_UART_TX_PIN - UART TX pin
#ifndef NRF_LOG_BACKEND_UART_TX_PIN
#define NRF_LOG_BACKEND_UART_TX_PIN 6
#endif

// <o> NRF_LOG_BACKEND_UART_BAUDRATE - Default Baudrate

// <323584=> 1200 baud
// <643072=> 2400 baud
// <1290240=> 4800 baud
// <2576384=> 9600 baud
// <3862528=> 14400 baud
// <5152768=> 19200 baud
// <7716864=> 28800 baud
// <10289152=> 38400 baud
// <15400960=> 57600 baud
// <20615168=> 76800 baud
// <30801920=> 115200 baud
// <61865984=> 230400 baud
// <67108864=> 250000 baud
// <121634816=> 460800 baud
// <251658240=> 921600 baud
// <268435456=> 1000000 baud

#ifndef NRF_LOG_BACKEND_UART_BAUDRATE
#define NRF_LOG_BACKEND_UART_BAUDRATE 30801920
#endif

// <o> NRF_LOG_BACKEND_UART_TEMP_BUFFER_SIZE - Size of buffer for partially processed strings.
// <i> Size of the buffer is a trade-off between RAM usage and processing.
// <i> if buffer is smaller then strings will often be fragmented.
// <i> It is recommended to use size which will fit typical log and only the
// <i> longer one will be fragmented.

#ifndef NRF_LOG_BACKEND_UART_TEMP_BUFFER_SIZE
#define NRF_LOG_BACKEND_UART_TEMP_BUFFER_SIZE 64
#endif

// </e>

// <h> nrf_log - Logging

//==========================================================
// <e> NRF_LOG_ENABLED - Logging module for nRF5 SDK
//==========================================================
#ifndef NRF_LOG_ENABLED
#define NRF_LOG_ENABLED 1
#endif
// <e> NRF_LOG_USES_COLORS - If enabled then ANSI escape code for colors is prefixed to every string
//==========================================================
#ifndef NRF_LOG_USES_COLORS
#define NRF_LOG_USES_COLORS 0
#endif
// <o> NRF_LOG_COLOR_DEFAULT - ANSI escape code prefix.

// <0=> Default
// <1=> Black
// <2=> Red
// <3=> Green
// <4=> Yellow
// <5=> Blue
// <6=> Magenta
// <7=> Cyan
// <8=> White

#ifndef NRF_LOG_COLOR_DEFAULT
#define NRF_LOG_COLOR_DEFAULT 0
#endif

// <o> NRF_LOG_ERROR_COLOR - ANSI escape code prefix.

// <0=> Default
// <1=> Black
// <2=> Red
// <3=> Green
// <4=> Yellow
// <5=> Blue
// <6=> Magenta
// <7=> Cyan
// <8=> White

#ifndef NRF_LOG_ERROR_COLOR
#define NRF_LOG_ERROR_COLOR 0
#endif

// <o> NRF_LOG_WARNING_COLOR - ANSI escape code prefix.

// <0=> Default
// <1=> Black
// <2=> Red
// <3=> Green
// <4=> Yellow
// <5=> Blue
// <6=> Magenta
// <7=> Cyan
// <8=> White

#ifndef NRF_LOG_WARNING_COLOR
#define NRF_LOG_WARNING_COLOR 0
#endif

// </e>

// <o> NRF_LOG_DEFAULT_LEVEL - Default Severity level

// <0=> Off
// <1=> Error
// <2=> Warning
// <3=> Info
// <4=> Debug

#ifndef NRF_LOG_DEFAULT_LEVEL
#define NRF_LOG_DEFAULT_LEVEL 4
#endif

// <q> NRF_LOG_DEFERRED - Enable deffered logger.

// <i> Log data is buffered and can be processed in idle.

#ifndef NRF_LOG_DEFERRED
#define NRF_LOG_DEFERRED 0
#endif

// <o> NRF_LOG_BUFSIZE - Size of the buffer for storing logs (in bytes).

// <i> Must be power of 2 and multiple of 4.
// <i> If NRF_LOG_DEFERRED = 0 then buffer size can be reduced to minimum.
// <128=> 128
// <256=> 256
// <512=> 512
// <1024=> 1024
// <2048=> 2048
// <4096=> 4096
// <8192=> 8192
// <16384=> 16384

#ifndef NRF_LOG_BUFSIZE
#define NRF_LOG_BUFSIZE 1024
#endif

// <q> NRF_LOG_ALLOW_OVERFLOW - Configures behavior when circular buffer is full.

// <i> If set then oldest logs are overwritten. Otherwise a
// <i> marker is injected informing about overflow.

#ifndef NRF_LOG_ALLOW_OVERFLOW
#define NRF_LOG_ALLOW_OVERFLOW 1
#endif

// <q> NRF_LOG_USES_TIMESTAMP - Enable timestamping

// <i> Function for getting the timestamp is provided by the user

#ifndef NRF_LOG_USES_TIMESTAMP
#define NRF_LOG_USES_TIMESTAMP 0
#endif

// <q> NRF_LOG_FILTERS_ENABLED - Enable dynamic filtering of logs.

#ifndef NRF_LOG_FILTERS_ENABLED
#define NRF_LOG_FILTERS_ENABLED 0
#endif

// <q> NRF_LOG_CLI_CMDS - Enable CLI commands for the module.

#ifndef NRF_LOG_CLI_CMDS
#define NRF_LOG_CLI_CMDS 0
#endif

// <h> Log message pool - Configuration of log message pool

//==========================================================
// <o> NRF_LOG_MSGPOOL_ELEMENT_SIZE - Size of a single element in the pool of memory objects.
// <i> If a small value is set, then performance of logs processing
// <i> is degraded because data is fragmented. Bigger value impacts
// <i> RAM memory utilization. The size is set to fit a message with
// <i> a timestamp and up to 2 arguments in a single memory object.

#ifndef NRF_LOG_MSGPOOL_ELEMENT_SIZE
#define NRF_LOG_MSGPOOL_ELEMENT_SIZE 20
#endif

// <o> NRF_LOG_MSGPOOL_ELEMENT_COUNT - Number of elements in the pool of memory objects
// <i> If a small value is set, then it may lead to a deadlock
// <i> in certain cases if backend has high latency and holds
// <i> multiple messages for long time. Bigger value impacts
// <i> RAM memory usage.

#ifndef NRF_LOG_MSGPOOL_ELEMENT_COUNT
#define NRF_LOG_MSGPOOL_ELEMENT_COUNT 8
#endif

// </h>
//==========================================================

[Einar Thorsrud]

Hi,

I expect the problem is that your application produces logs faster than they are processed. Even if you don't use deferred logging, the RTT buffer will eventually fill up if you log too fast.

There are a few possible ways to handle this:

• Increase the RTT buffer size
• Reduce the amount of logging

You could also consider using deferred logging with a very large NRF_LOG_BUFSIZE. Assuming your application only produces a large number of logs for a short time, then it would perhaps have time to process the logs later when things settle down.

[Muhammet YILDIZ]

Hi

Even if i increse the NRF_LOG_BUFSIZE to 16384, nothing changes.

But when i increase SEGGER_RTT_CONFIG_BUFFER_SIZE_UP to 512, it solves my problem for now.

[Einar Thorsrud]

Hi,

I am glad to hear you got it working.

(By the way, it makes sense that increasing NRF_LOG_BUFSIZE does not work if that is all you changed. The lager buffer is only useful in case you use deferred logging, which you are not.)

[Muhammet YILDIZ]

Acctualy it is not. For small strings yes it is working well. But in my case it is not.

I am building json objects and it is little nested and have some nested arrays and objects.

I closed almost all the nrf_logs (committed) and almost only one is available. That takes a char pointer which is printing json string.

Still i cant get all the message i need to see.

I have see it preperly to detect json problems and see any memory lekages. When i finish my job, i am planing to delete json print and close de debug define.

So i realy need the log works preparly. Please can you help me with this?

When i enable defered option, there is no message on the segger rtt viewer.

[awneil]

Einar Thorsrud said:

I expect the problem is that your application produces logs faster than they are processed. Even if you don't use deferred logging, the RTT buffer will eventually fill up if you log too fast.

I have found that it is very easy to log "too fast".

Or, in other words, the RTT logging is rather "low bandwidth".

So you really need to minimise the amount of debug you're sending.

I don't know if you can get any better performance over the UART ... ?

Make sure that you don't have this error in your NRF_LOG_PROCESS handling: https://devzone.nordicsemi.com/f/nordic-q-a/34666/nrf5-sdk-v15-0-0-bug-report-incorrect-use-of-nrf_log_process-in-ble_app_uart-peripheral-example-among-others

[Einar Thorsrud]

I see.

It might be worth a shot to try deferred logging with a large NRF_LOG_BUFSIZE, then. As you don't get any log output with deferred logging I wonder if you handle printing of logs in your main loop, typically before going to sleep? You can refer to any of the example applications in the SDK that use deferred logging or the Logger module documentation for how to do it. Essentially you need to call NRF_LOG_PROCESS() repeatedly until it returns false (indicating that there are no more logs to process) before going to sleep.